USB 1.1 Full Speed OHCI slow/high latency

USB 1.1 Full Speed OHCI slow/high latency

[ValdikSS]

I have an old USB 1.1 Full Speed printer (Canon LBP1120) which can't 
print large documents due to insufficient USB 1.1 transfer speed/high 
latency on Linux.
I believe this may be Linux OHCI bug or deficiency.

If I connect the printer to USB 2.0 port (uses "companion" OHCI 
controller), the printing engine reports data underflow using its 
proprietary command protocol, and the full-page picture fails to print 
(only 1/3 is printed).
However if I connect it over USB 2.0 Hub (EHCI, hub does internal Full 
Speed conversion) the printer works fine.
Same applies to USB 3.0 XHCI ports, via which the printer also works fine.

The issue is seen on Orange Pi Zero3 (Allwinner H618) and Radxa Rock S 
(Rockchip 3308) boards, with different USB controllers.

There's no USB-level errors (captured with tcpdump -i usbmon0), all URBs 
are success, but they are much slower in OHCI than with EHCI Full Speed 
via hub.

Here's a speed comparison using simple Python script with asks the 
printer status 10000 times.

Direct connection, OHCI:

# python3 speedtest.py
Opening printer at /dev/usb/lp0...
Testing 10000/10000...
Avg delta: 1.916 ms
Min: 1.443 ms
Max: 2.891 ms

Connection via the USB 2.0 hub, EHCI:

# python3 speedtest.py
Opening printer at /dev/usb/lp0...
Testing 10000/10000...
Avg delta: 0.696 ms
Min: 0.590 ms
Max: 1.072 ms

The printer is from year 2002, with USB 1.1 full speed, and was designed 
to work via USB 1.1 controllers.
Any ideas what could be wrong?


# lsusb -vvv
Bus 003 Device 004: ID 04a9:262b Canon, Inc. LaserShot LBP-1120 Printer
Device Descriptor:
   bLength                18
   bDescriptorType         1
   bcdUSB               1.10
   bDeviceClass            0
   bDeviceSubClass         0
   bDeviceProtocol         0
   bMaxPacketSize0         8
   idVendor           0x04a9 Canon, Inc.
   idProduct          0x262b LaserShot LBP-1120 Printer
   bcdDevice            1.00
   iManufacturer           1 Canon
   iProduct                2 Canon CAPT USB Printer
   iSerial                 3 0441BFZ2
   bNumConfigurations      1
   Configuration Descriptor:
     bLength                 9
     bDescriptorType         2
     wTotalLength       0x0020
     bNumInterfaces          1
     bConfigurationValue     1
     iConfiguration          0
     bmAttributes         0xc0
       Self Powered
     MaxPower                0mA
     Interface Descriptor:
       bLength                 9
       bDescriptorType         4
       bInterfaceNumber        0
       bAlternateSetting       0
       bNumEndpoints           2
       bInterfaceClass         7 Printer
       bInterfaceSubClass      1 Printer
       bInterfaceProtocol      2 Bidirectional
       iInterface              0
       Endpoint Descriptor:
         bLength                 7
         bDescriptorType         5
         bEndpointAddress     0x01  EP 1 OUT
         bmAttributes            2
           Transfer Type            Bulk
           Synch Type               None
           Usage Type               Data
         wMaxPacketSize     0x0040  1x 64 bytes
         bInterval               0
       Endpoint Descriptor:
         bLength                 7
         bDescriptorType         5
         bEndpointAddress     0x82  EP 2 IN
         bmAttributes            2
           Transfer Type            Bulk
           Synch Type               None
           Usage Type               Data
         wMaxPacketSize     0x0040  1x 64 bytes
         bInterval               0
can't get debug descriptor: Resource temporarily unavailable
Device Status:     0x0001
   Self Powered



# lsusb -tv
/:  Bus 06.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
     ID 1d6b:0001 Linux Foundation 1.1 root hub
/:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
     ID 1d6b:0001 Linux Foundation 1.1 root hub
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
     ID 1d6b:0002 Linux Foundation 2.0 root hub
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
     ID 1d6b:0001 Linux Foundation 1.1 root hub
     |__ Port 1: Dev 4, If 0, Class=Printer, Driver=usblp, 12M
         ID 04a9:262b Canon, Inc. LaserShot LBP-1120 Printer
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
     ID 1d6b:0002 Linux Foundation 2.0 root hub
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
     ID 1d6b:0002 Linux Foundation 2.0 root hub

Re: USB 1.1 Full Speed OHCI slow/high latency

[Greg KH]

On Thu, Aug 14, 2025 at 04:56:40AM +0300, ValdikSS wrote:
> I have an old USB 1.1 Full Speed printer (Canon LBP1120) which can't print
> large documents due to insufficient USB 1.1 transfer speed/high latency on
> Linux.
> I believe this may be Linux OHCI bug or deficiency.
> 
> If I connect the printer to USB 2.0 port (uses "companion" OHCI controller),
> the printing engine reports data underflow using its proprietary command
> protocol, and the full-page picture fails to print (only 1/3 is printed).
> However if I connect it over USB 2.0 Hub (EHCI, hub does internal Full Speed
> conversion) the printer works fine.
> Same applies to USB 3.0 XHCI ports, via which the printer also works fine.
> 
> The issue is seen on Orange Pi Zero3 (Allwinner H618) and Radxa Rock S
> (Rockchip 3308) boards, with different USB controllers.
> 
> There's no USB-level errors (captured with tcpdump -i usbmon0), all URBs are
> success, but they are much slower in OHCI than with EHCI Full Speed via hub.
> 
> Here's a speed comparison using simple Python script with asks the printer
> status 10000 times.
> 
> Direct connection, OHCI:
> 
> # python3 speedtest.py
> Opening printer at /dev/usb/lp0...
> Testing 10000/10000...
> Avg delta: 1.916 ms
> Min: 1.443 ms
> Max: 2.891 ms
> 
> Connection via the USB 2.0 hub, EHCI:
> 
> # python3 speedtest.py
> Opening printer at /dev/usb/lp0...
> Testing 10000/10000...
> Avg delta: 0.696 ms
> Min: 0.590 ms
> Max: 1.072 ms
> 
> The printer is from year 2002, with USB 1.1 full speed, and was designed to
> work via USB 1.1 controllers.
> Any ideas what could be wrong?

Yes, the USB controllers on these devices just can't handle it, odds are
they were never really designed for this type of workload.

Stick with the hub solution, scheduling low speed transactions is a pain
for many host controllers and it seems that it's better done by the USB
3 controller than the older ones.

If you really want to dig into this, perhaps the output of usbmon when
the device is failing might provide some information as to what is going
on.

thanks,

greg k-h

Re: USB 1.1 Full Speed OHCI slow/high latency

[Alan Stern]

On Thu, Aug 14, 2025 at 04:56:40AM +0300, ValdikSS wrote:
> I have an old USB 1.1 Full Speed printer (Canon LBP1120) which can't print
> large documents due to insufficient USB 1.1 transfer speed/high latency on
> Linux.
> I believe this may be Linux OHCI bug or deficiency.
> 
> If I connect the printer to USB 2.0 port (uses "companion" OHCI controller),
> the printing engine reports data underflow using its proprietary command
> protocol, and the full-page picture fails to print (only 1/3 is printed).

Why on earth would a printer protocol have speed/latency requirements?  
That's just bad design.  It's not like printers are under any severe 
time constraints -- they won't blow up if they have to wait an extra ten 
seconds for the computer to send the contents of a page.

> However if I connect it over USB 2.0 Hub (EHCI, hub does internal Full Speed
> conversion) the printer works fine.
> Same applies to USB 3.0 XHCI ports, via which the printer also works fine.

USB 2 and USB 3 are inherently faster than USB 1.1, even when 
communicating with a full-speed device.

> The issue is seen on Orange Pi Zero3 (Allwinner H618) and Radxa Rock S
> (Rockchip 3308) boards, with different USB controllers.
> 
> There's no USB-level errors (captured with tcpdump -i usbmon0), all URBs are
> success, but they are much slower in OHCI than with EHCI Full Speed via hub.

The timing information in the usbmon traces will contain helpful clues 
about what's going on, especially if the OHCI trace is compared to the 
EHCI trace.  (Incidentally, you shouldn't use usbmon0; you should the 
bus number that the printer is attached to.)

> Here's a speed comparison using simple Python script with asks the printer
> status 10000 times.
> 
> Direct connection, OHCI:
> 
> # python3 speedtest.py
> Opening printer at /dev/usb/lp0...
> Testing 10000/10000...
> Avg delta: 1.916 ms
> Min: 1.443 ms
> Max: 2.891 ms
> 
> Connection via the USB 2.0 hub, EHCI:
> 
> # python3 speedtest.py
> Opening printer at /dev/usb/lp0...
> Testing 10000/10000...
> Avg delta: 0.696 ms
> Min: 0.590 ms
> Max: 1.072 ms

Without knowing what these numbers refer to, it's hard to say anything 
useful.  About all I can glean is that EHCI is faster than OHCI, which 
we already know.

> The printer is from year 2002, with USB 1.1 full speed, and was designed to
> work via USB 1.1 controllers.
> Any ideas what could be wrong?

No.  Have you tried using the printer on a computer with a different 
(non-Linux) operating system?

Alan Stern

Re: USB 1.1 Full Speed OHCI slow/high latency

[ValdikSS]

On 14.08.2025 5:24 PM, Alan Stern wrote:
> On Thu, Aug 14, 2025 at 04:56:40AM +0300, ValdikSS wrote:
>> I have an old USB 1.1 Full Speed printer (Canon LBP1120) which can't print
>> large documents due to insufficient USB 1.1 transfer speed/high latency on
>> Linux.
>> I believe this may be Linux OHCI bug or deficiency.
>>
>> If I connect the printer to USB 2.0 port (uses "companion" OHCI controller),
>> the printing engine reports data underflow using its proprietary command
>> protocol, and the full-page picture fails to print (only 1/3 is printed).
> 
> Why on earth would a printer protocol have speed/latency requirements?
> That's just bad design.  It's not like printers are under any severe
> time constraints -- they won't blow up if they have to wait an extra ten
> seconds for the computer to send the contents of a page.

That's a very old printer from the lower-end segment, which have so 
little RAM that it requires page (not job) streaming from the PC.
AFAIK it has 512 KB of RAM, and the whole-page picture compressed to the 
printer language (CAPTv1) is around 1.5 MB.

The printer doesn't use regular usb EP stall feature to tell the host 
that it shouldn't send any more data. Instead, it uses bi-directional 
protocol where the host polls the printer status every time during the 
printing process, and checks whether printer says it can accept the data.

So it's constant:
1. Hey printer, tell me your BasicStatus
2. Here it is, 6 bytes of data
3. Hey printer, tell me your ExtendedStatus
4. Here it is, first BasicStatus again, then ExtendedStatus 16 bytes in 
the next USB transfer
5. So you're ready to accept the data? Here you are, your <=6144 raster.
6. Hey printer, tell me your BasicStatus...

You can imagine how inefficient is that for USB 1.1.

And a single USB transfer raster data is limited to 6144 bytes in the 
"driver" (CUPS filter) for some reason. This doesn't seem to be a 
printer hardware limitation: I've patched this limit to 16128 and it 
seems to work as a workaround for this issue (more data in a single USB 
transfer).

This is an official proprietary x86 Canon driver. I'm running it on ARM 
via both qemu and box86 (and the interpretation performance is not an 
issue here, I checked that. It works fine on much lower-end SBC which 
has MUSB stack with EHCI only).


> The timing information in the usbmon traces will contain helpful clues
> about what's going on, especially if the OHCI trace is compared to the
> EHCI trace.  (Incidentally, you shouldn't use usbmon0; you should the
> bus number that the printer is attached to.)

The "success" response on OUT raster data takes about 2-2.5x longer with 
OHCI than via the hub. And I can't say it's too slow either, everything 
seems to be more or less fine regarding the timings, but the printer 
doesn't like it, reporting NOT_READY | OFFLINE in BasicStatus and 
UNDERFLOW in Engine ExtendedStatus.

I'm not very versed in USB though.
I can upload .pcaps if that's useful.


> 
>> Here's a speed comparison using simple Python script with asks the printer
>> status 10000 times.
>>
>> Direct connection, OHCI:
>>
>> # python3 speedtest.py
>> Opening printer at /dev/usb/lp0...
>> Testing 10000/10000...
>> Avg delta: 1.916 ms
>> Min: 1.443 ms
>> Max: 2.891 ms
>>
>> Connection via the USB 2.0 hub, EHCI:
>>
>> # python3 speedtest.py
>> Opening printer at /dev/usb/lp0...
>> Testing 10000/10000...
>> Avg delta: 0.696 ms
>> Min: 0.590 ms
>> Max: 1.072 ms
> 
> Without knowing what these numbers refer to, it's hard to say anything
> useful.  About all I can glean is that EHCI is faster than OHCI, which
> we already know.

The speedtest.py requests BasicStatus and reads the response in a loop.

> 
>> The printer is from year 2002, with USB 1.1 full speed, and was designed to
>> work via USB 1.1 controllers.
>> Any ideas what could be wrong?
> 
> No.  Have you tried using the printer on a computer with a different
> (non-Linux) operating system?

I think I have a PC on LGA775 which may have OHCI support. I'll try the 
speedtest.py under Windows XP or 7.

> 
> Alan Stern

Re: USB 1.1 Full Speed OHCI slow/high latency

[Alan Stern]

On Thu, Aug 14, 2025 at 06:11:59PM +0300, ValdikSS wrote:
> On 14.08.2025 5:24 PM, Alan Stern wrote:
> > On Thu, Aug 14, 2025 at 04:56:40AM +0300, ValdikSS wrote:
> > > I have an old USB 1.1 Full Speed printer (Canon LBP1120) which can't print
> > > large documents due to insufficient USB 1.1 transfer speed/high latency on
> > > Linux.
> > > I believe this may be Linux OHCI bug or deficiency.
> > > 
> > > If I connect the printer to USB 2.0 port (uses "companion" OHCI controller),
> > > the printing engine reports data underflow using its proprietary command
> > > protocol, and the full-page picture fails to print (only 1/3 is printed).
> > 
> > Why on earth would a printer protocol have speed/latency requirements?
> > That's just bad design.  It's not like printers are under any severe
> > time constraints -- they won't blow up if they have to wait an extra ten
> > seconds for the computer to send the contents of a page.
> 
> That's a very old printer from the lower-end segment, which have so little
> RAM that it requires page (not job) streaming from the PC.
> AFAIK it has 512 KB of RAM, and the whole-page picture compressed to the
> printer language (CAPTv1) is around 1.5 MB.
> 
> The printer doesn't use regular usb EP stall feature to tell the host that
> it shouldn't send any more data. Instead, it uses bi-directional protocol
> where the host polls the printer status every time during the printing
> process, and checks whether printer says it can accept the data.
> 
> So it's constant:
> 1. Hey printer, tell me your BasicStatus
> 2. Here it is, 6 bytes of data
> 3. Hey printer, tell me your ExtendedStatus
> 4. Here it is, first BasicStatus again, then ExtendedStatus 16 bytes in the
> next USB transfer
> 5. So you're ready to accept the data? Here you are, your <=6144 raster.
> 6. Hey printer, tell me your BasicStatus...
> 
> You can imagine how inefficient is that for USB 1.1.

Yes, but I can't imagine why delays would cause a NOTREADY, OFFLINE, or 
UNDERFLOW error.

> And a single USB transfer raster data is limited to 6144 bytes in the
> "driver" (CUPS filter) for some reason. This doesn't seem to be a printer
> hardware limitation: I've patched this limit to 16128 and it seems to work
> as a workaround for this issue (more data in a single USB transfer).
> 
> This is an official proprietary x86 Canon driver. I'm running it on ARM via
> both qemu and box86 (and the interpretation performance is not an issue
> here, I checked that. It works fine on much lower-end SBC which has MUSB
> stack with EHCI only).
> 
> 
> > The timing information in the usbmon traces will contain helpful clues
> > about what's going on, especially if the OHCI trace is compared to the
> > EHCI trace.  (Incidentally, you shouldn't use usbmon0; you should the
> > bus number that the printer is attached to.)
> 
> The "success" response on OUT raster data takes about 2-2.5x longer with
> OHCI than via the hub. And I can't say it's too slow either, everything
> seems to be more or less fine regarding the timings, but the printer doesn't
> like it, reporting NOT_READY | OFFLINE in BasicStatus and UNDERFLOW in
> Engine ExtendedStatus.
> 
> I'm not very versed in USB though.
> I can upload .pcaps if that's useful.
> 
> 
> > 
> > > Here's a speed comparison using simple Python script with asks the printer
> > > status 10000 times.
> > > 
> > > Direct connection, OHCI:
> > > 
> > > # python3 speedtest.py
> > > Opening printer at /dev/usb/lp0...
> > > Testing 10000/10000...
> > > Avg delta: 1.916 ms
> > > Min: 1.443 ms
> > > Max: 2.891 ms
> > > 
> > > Connection via the USB 2.0 hub, EHCI:
> > > 
> > > # python3 speedtest.py
> > > Opening printer at /dev/usb/lp0...
> > > Testing 10000/10000...
> > > Avg delta: 0.696 ms
> > > Min: 0.590 ms
> > > Max: 1.072 ms
> > 
> > Without knowing what these numbers refer to, it's hard to say anything
> > useful.  About all I can glean is that EHCI is faster than OHCI, which
> > we already know.
> 
> The speedtest.py requests BasicStatus and reads the response in a loop.

Either .pcap files or the usbmon text output for both of these tests 
would be good.  But set the number of iterations to something very 
small, like 10 or so.  No point posting a log containing thousands of 
repetitions of the same information...

Alan Stern

Re: USB 1.1 Full Speed OHCI slow/high latency

[ValdikSS]

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

On 14.08.2025 7:40 PM, Alan Stern wrote:
> Yes, but I can't imagine why delays would cause a NOTREADY, OFFLINE, or
> UNDERFLOW error.

The laser printers roll the paper with the constant speed, they don't 
slow down when they have insufficient data.

If the host doesn't send the image data in time (and here it happens 
during the print of a single page just as it rolls, as it is too large 
to fit into the printer's RAM), the job is marked as failed due to 
underflow of print data.

It's similar to CnC device in that sense. Modern printers wait for the 
full page, but this printer is from the era when RAM was expensive and 
could not (reliably) fit the whole page.


> Either .pcap files or the usbmon text output for both of these tests
> would be good.  But set the number of iterations to something very
> small, like 10 or so.  No point posting a log containing thousands of
> repetitions of the same information...

Here you are, check the attachment. It's a 30 times loop.

Also tried the speedtest.py on an old HP T510 thin client (x86, VIA 
chipset, UHCI), and the speeds are fine.

Avg delta: 0.990 ms
Min: 0.870 ms
Max: 1.984 ms

My guess it's OHCI to blame.

[-- Attachment #2: usb11-usb20-capture.zip --]
[-- Type: application/zip, Size: 3440 bytes --]

Re: USB 1.1 Full Speed OHCI slow/high latency

[Alan Stern]

On Fri, Aug 15, 2025 at 11:39:03AM +0300, ValdikSS wrote:
> On 14.08.2025 7:40 PM, Alan Stern wrote:
> > Either .pcap files or the usbmon text output for both of these tests
> > would be good.  But set the number of iterations to something very
> > small, like 10 or so.  No point posting a log containing thousands of
> > repetitions of the same information...
> 
> Here you are, check the attachment. It's a 30 times loop.
> 
> Also tried the speedtest.py on an old HP T510 thin client (x86, VIA chipset,
> UHCI), and the speeds are fine.
> 
> Avg delta: 0.990 ms
> Min: 0.870 ms
> Max: 1.984 ms
> 
> My guess it's OHCI to blame.

The OHCI pcap file shows that transfers take place at intervals of 2 ms, 
which is perhaps slower than expected.  (The EHCI transfers take place 
at intervals of 0.625 or 0.875 ms, which is reasonable.)

I think the reason the OHCI transfers need 2 ms rather than 1 ms is 
because of the way the driver unlinks empty Endpoint Descriptors.  Lines 
1165-1168 of drivers/usb/host/ohci-q.c do this:

	/* clean schedule:  unlink EDs that are no longer busy */
	if (list_empty(&ed->td_list)) {
		if (ed->state == ED_OPER)
			start_ed_unlink(ohci, ed);

As a result, each time a transfer finishes the ED is unlinked, and each 
time a new transfer starts the ED has to be linked again.  Presumably (I 
don't recall all the details about how OHCI works so this is just my 
guess) those steps each require 1 ms, accounting for the 2-ms time 
interval between transfers.

You could try deleting or commenting out the last two of those lines to 
see if it makes a difference.  (Note that this is not a permanent 
solution; without the call to start_ed_unlink(), the memory used by the 
ED will never be freed.  A better approach would be to unlink EDs after 
they have been idle for some minimum time rather than right away.)

Of course, what's going on when you try to print something may be 
different from this simple test.

Alan Stern

Re: USB 1.1 Full Speed OHCI slow/high latency

[ValdikSS]

On 15.08.2025 5:52 PM, Alan Stern wrote:
>> My guess it's OHCI to blame.
> 
> The OHCI pcap file shows that transfers take place at intervals of 2 ms,
> which is perhaps slower than expected.  (The EHCI transfers take place
> at intervals of 0.625 or 0.875 ms, which is reasonable.)
> 
> I think the reason the OHCI transfers need 2 ms rather than 1 ms is
> because of the way the driver unlinks empty Endpoint Descriptors.  Lines
> 1165-1168 of drivers/usb/host/ohci-q.c do this:
> 
> 	/* clean schedule:  unlink EDs that are no longer busy */
> 	if (list_empty(&ed->td_list)) {
> 		if (ed->state == ED_OPER)
> 			start_ed_unlink(ohci, ed);
> 
> As a result, each time a transfer finishes the ED is unlinked, and each
> time a new transfer starts the ED has to be linked again.  Presumably (I
> don't recall all the details about how OHCI works so this is just my
> guess) those steps each require 1 ms, accounting for the 2-ms time
> interval between transfers.
> 
> You could try deleting or commenting out the last two of those lines to
> see if it makes a difference.  (Note that this is not a permanent
> solution; without the call to start_ed_unlink(), the memory used by the
> ED will never be freed.  A better approach would be to unlink EDs after
> they have been idle for some minimum time rather than right away.)

Thanks Alan, this definitely makes things better

Before the patch:

Avg delta: 1.916 ms
Min: 1.443 ms
Max: 2.891 ms

After the patch:

Avg delta: 0.944 ms
Min: 0.722 ms
Max: 6.904 ms

However the printout is still not in full. Now the same picture prints 
about 4/5 of the page, but still not 100% (previously it failed on 1/3).

Would the .pcap of the printing process be useful?

Re: USB 1.1 Full Speed OHCI slow/high latency

[Alan Stern]

On Fri, Aug 15, 2025 at 06:53:33PM +0300, ValdikSS wrote:
> Thanks Alan, this definitely makes things better
> 
> Before the patch:
> 
> Avg delta: 1.916 ms
> Min: 1.443 ms
> Max: 2.891 ms
> 
> After the patch:
> 
> Avg delta: 0.944 ms
> Min: 0.722 ms
> Max: 6.904 ms

I guess that 6.9 ms maximum occurred because the test process was 
preempted.  Not the sort of thing you can easily prevent.

> However the printout is still not in full. Now the same picture prints about
> 4/5 of the page, but still not 100% (previously it failed on 1/3).
> 
> Would the .pcap of the printing process be useful?

I rather doubt it.  You might be able to figure something out by looking 
at the timing of the various transfers, particularly near the end when 
the underflow occurred.  But I don't even know what the printer's timing 
requirements are (and maybe you don't either).

Overall this probably isn't a battle worth fighting.  Either just attach 
the printer to a high-speed hub or get a better printer.

Alan Stern

Re: USB 1.1 Full Speed OHCI slow/high latency

[ValdikSS]

On 15.08.2025 8:07 PM, Alan Stern wrote:
>> However the printout is still not in full. Now the same picture prints about
>> 4/5 of the page, but still not 100% (previously it failed on 1/3).
>>
>> Would the .pcap of the printing process be useful?
> 
> I rather doubt it.  You might be able to figure something out by looking
> at the timing of the various transfers, particularly near the end when
> the underflow occurred.  But I don't even know what the printer's timing
> requirements are (and maybe you don't either).
> 
> Overall this probably isn't a battle worth fighting.  Either just attach
> the printer to a high-speed hub or get a better printer.

I *buy* these legacy devices to improve them in Linux :)

I'm making an open-source print server hardware for older printers, 
that's why for me this issue is worth researching, at least to document 
such hardware heisenbugs.
There've been different USB behavior and incompatibilities with scanners 
(fixed it in SANE) and printers (fixed by CUPS quirks file), but this is 
the first time I'm going down to USB HC level.

This printer (Canon LBP1120) does not have drivers for 64-bit Windows or 
recent macOS, that's why for many it's a paperweight device you can't 
use or sell, unless fixed by other means (usually a VM with 32-bit 
Windows, and now my print server as well).

You gave me directions where I should look for, because I didn't know 
how to start debugging without the logic analyzer.
Usbmon captures only USB communication packets and some of USB HUB 
controlling packets (such as TT related), but does not include 
device-controlling MMIO registers, which was the case here.

I'll add debug prints to everything related to MMIO and take a look what 
could be improved. Thanks!
If you have other ideas I could try right away, please share them!

Re: USB 1.1 Full Speed OHCI slow/high latency

[Alan Stern]

On Fri, Aug 15, 2025 at 09:13:09PM +0300, ValdikSS wrote:
> I *buy* these legacy devices to improve them in Linux :)
> 
> I'm making an open-source print server hardware for older printers, that's
> why for me this issue is worth researching, at least to document such
> hardware heisenbugs.
> There've been different USB behavior and incompatibilities with scanners
> (fixed it in SANE) and printers (fixed by CUPS quirks file), but this is the
> first time I'm going down to USB HC level.
> 
> This printer (Canon LBP1120) does not have drivers for 64-bit Windows or
> recent macOS, that's why for many it's a paperweight device you can't use or
> sell, unless fixed by other means (usually a VM with 32-bit Windows, and now
> my print server as well).
> 
> You gave me directions where I should look for, because I didn't know how to
> start debugging without the logic analyzer.
> Usbmon captures only USB communication packets and some of USB HUB
> controlling packets (such as TT related), but does not include
> device-controlling MMIO registers, which was the case here.
> 
> I'll add debug prints to everything related to MMIO and take a look what
> could be improved. Thanks!

Good luck!

> If you have other ideas I could try right away, please share them!

You might compare the usbmon traces for your patched OHCI against a UHCI 
system.  They should run at approximately the same speed, so it's not 
clear why the printer would work with one but not the other.

Alan Stern

Re: USB 1.1 Full Speed OHCI slow/high latency

[ValdikSS]

On 16.08.2025 5:04 AM, Alan Stern wrote:
>> You gave me directions where I should look for, because I didn't know how to
>> start debugging without the logic analyzer.
>> Usbmon captures only USB communication packets and some of USB HUB
>> controlling packets (such as TT related), but does not include
>> device-controlling MMIO registers, which was the case here.
>>
>> I'll add debug prints to everything related to MMIO and take a look what
>> could be improved. Thanks!
> 
> Good luck!
> 
>> If you have other ideas I could try right away, please share them!
> 
> You might compare the usbmon traces for your patched OHCI against a UHCI
> system.  They should run at approximately the same speed, so it's not
> clear why the printer would work with one but not the other.

Alan, Greg, I found the reason for 1 ms delay: it is artificial, added 
in v2.5.21 as a possible race condition fix:

> /* SF interrupt might get delayed; record the frame counter value that
>  * indicates when the HC isn't looking at it, so concurrent unlinks
>  * behave.  frame_no wraps every 2^16 msec, and changes right before
>  * SF is triggered.
>  */
> ed->tick = le16_to_cpu (ohci->hcca->frame_no) + 1;

https://git.kernel.org/pub/scm/linux/kernel/git/tglx/history.git/commit/drivers/usb/host/ohci-q.c?id=9a53bdfbe26329e78f43485fc43f5fab5f27cbbc

ED it just not getting processed at all until the time (counted by 
frame_no) is reached, apparently there is/was no other way to ensure HC 
is finished with this ED.

> /* only take off EDs that the HC isn't using, accounting for
>  * frame counter wraps.  completion callbacks might prepend
>  * EDs to the list, they'll be checked next irq.
>  */
> if (tick_before (tick, ed->tick)) {
>     last = &ed->ed_rm_list;
>     continue;
> }

I removed "+ 1" and it removed that 1ms delay. Doesn't seem to break 
anything in my setup. UHCI code doesn't seem to have any similar delays.

Could it be relevant only for hardware of its era? If I add "no +1" code 
quirk as a module option, disabled by default, does it sounds sane to you?

Re: USB 1.1 Full Speed OHCI slow/high latency

[Alan Stern]

On Mon, Sep 22, 2025 at 02:11:43AM +0300, ValdikSS wrote:
> Alan, Greg, I found the reason for 1 ms delay: it is artificial, added in
> v2.5.21 as a possible race condition fix:
> 
> > /* SF interrupt might get delayed; record the frame counter value that
> >  * indicates when the HC isn't looking at it, so concurrent unlinks
> >  * behave.  frame_no wraps every 2^16 msec, and changes right before
> >  * SF is triggered.
> >  */
> > ed->tick = le16_to_cpu (ohci->hcca->frame_no) + 1;
> 
> https://git.kernel.org/pub/scm/linux/kernel/git/tglx/history.git/commit/drivers/usb/host/ohci-q.c?id=9a53bdfbe26329e78f43485fc43f5fab5f27cbbc
> 
> ED it just not getting processed at all until the time (counted by frame_no)
> is reached, apparently there is/was no other way to ensure HC is finished
> with this ED.
> 
> > /* only take off EDs that the HC isn't using, accounting for
> >  * frame counter wraps.  completion callbacks might prepend
> >  * EDs to the list, they'll be checked next irq.
> >  */
> > if (tick_before (tick, ed->tick)) {
> >     last = &ed->ed_rm_list;
> >     continue;
> > }

Good work tracking that down!

> I removed "+ 1" and it removed that 1ms delay. Doesn't seem to break
> anything in my setup. UHCI code doesn't seem to have any similar delays.
> 
> Could it be relevant only for hardware of its era? If I add "no +1" code
> quirk as a module option, disabled by default, does it sounds sane to you?

I'm not sure that there is any OHCI hardware from later than that era. 
But regardless...

Module options are frowned upon these days.  Instead you could add a 
sysfs (or even debugfs) attribute file for controlling that "+ 1".

Alan Stern

Re: USB 1.1 Full Speed OHCI slow/high latency

[ValdikSS]

On 22.09.2025 5:16 PM, Alan Stern wrote:
> On Mon, Sep 22, 2025 at 02:11:43AM +0300, ValdikSS wrote:
>> Alan, Greg, I found the reason for 1 ms delay: it is artificial, added in
>> v2.5.21 as a possible race condition fix:
> 
> Good work tracking that down!
> 
>> I removed "+ 1" and it removed that 1ms delay. Doesn't seem to break
>> anything in my setup. UHCI code doesn't seem to have any similar delays.
>>
>> Could it be relevant only for hardware of its era? If I add "no +1" code
>> quirk as a module option, disabled by default, does it sounds sane to you?
> 
> I'm not sure that there is any OHCI hardware from later than that era.
> But regardless...
> 
> Module options are frowned upon these days.  Instead you could add a
> sysfs (or even debugfs) attribute file for controlling that "+ 1".

I just implemented another approach: do not unlink the ED right away, 
instead mark it IDLE and unlink only if no consecutive transfers are 
performed after the timeout. This still preserves one-frame delay while 
unlinking, should be safe.

Please take a look if you have free time. I'm no kernel developer by any 
means :)

Re: USB 1.1 Full Speed OHCI slow/high latency

[Alan Stern]

On Mon, Sep 22, 2025 at 05:38:38PM +0300, ValdikSS wrote:
> On 22.09.2025 5:16 PM, Alan Stern wrote:
> > On Mon, Sep 22, 2025 at 02:11:43AM +0300, ValdikSS wrote:
> > > Alan, Greg, I found the reason for 1 ms delay: it is artificial, added in
> > > v2.5.21 as a possible race condition fix:
> > 
> > Good work tracking that down!
> > 
> > > I removed "+ 1" and it removed that 1ms delay. Doesn't seem to break
> > > anything in my setup. UHCI code doesn't seem to have any similar delays.
> > > 
> > > Could it be relevant only for hardware of its era? If I add "no +1" code
> > > quirk as a module option, disabled by default, does it sounds sane to you?
> > 
> > I'm not sure that there is any OHCI hardware from later than that era.
> > But regardless...
> > 
> > Module options are frowned upon these days.  Instead you could add a
> > sysfs (or even debugfs) attribute file for controlling that "+ 1".
> 
> I just implemented another approach: do not unlink the ED right away,
> instead mark it IDLE and unlink only if no consecutive transfers are
> performed after the timeout. This still preserves one-frame delay while
> unlinking, should be safe.

That does indeed sound like a better approach.

> Please take a look if you have free time.

Feel free to post your patch on the mailing list for review.

>  I'm no kernel developer by any
> means :)

Seems like you're becoming one, like it or not!  Welcome to the 
community.

Alan Stern

[PATCH] usb: ohci: delay endpoint descriptor unlinking to reduce transfer latency

[ValdikSS]

The current OHCI implementation immediately unlinks Endpoint Descriptors (EDs)
when they become idle. Unlinking process waits for the next Start of Frame (SOF)
interrupt as a synchronization primitive before unlinking it.

This adds ~1ms latency per transfer cycle for rapid bidirectional communication
which leads to half the USB 1.1 speed for smaller packets at best.

When a transfer completes, takeback_td() immediately calls start_ed_unlink()
if the ED has no more TDs queued. This triggers:
1. ED marked for unlinking with SOF interrupt enabled
2. Wait for next 1ms frame boundary (SOF interrupt)
3. finish_unlinks() processes the ED removal

This patch adds 275+10 ms timeout to the idle EDs. If new transfers
arrive on the same ED before timeout expiry, clear the timeout and continue
using the ED. Only unlink EDs that remain idle after the timeout period
are cleared by the existing I/O watchdog, which runs every 275 ms (and
the ED timeout is 10 ms).

This eliminates SOF synchronization delays for consecutive transfers,
but preserves the one-frame unlinking delay which was added as a
race condition elimination measure before the modern git history
in commit 961c380cef (March 2004) by David Brownell.

Performance Impact:
Tested on Orange Pi Zero3 (Allwinner H618) with Canon LBP1120 printer:
- Before: 1.984ms average latency (write-read pattern)
- After:  0.981ms average latency

Link: https://lore.kernel.org/all/9013fce0-6764-49b1-9e54-68e915e12d7c@valdikss.org.ru/T/
---
 drivers/usb/host/ohci-hcd.c | 18 ++++++++++++++++++
 drivers/usb/host/ohci-q.c   | 15 ++++++++++++---
 drivers/usb/host/ohci.h     |  1 +
 3 files changed, 31 insertions(+), 3 deletions(-)

diff --git a/drivers/usb/host/ohci-hcd.c b/drivers/usb/host/ohci-hcd.c
index 9c7f30086..daaa03dd6 100644
--- a/drivers/usb/host/ohci-hcd.c
+++ b/drivers/usb/host/ohci-hcd.c
@@ -364,6 +364,7 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
 	if (ohci->rh_state != OHCI_RH_RUNNING) {
 sanitize:
 		ed->state = ED_IDLE;
+		ed->idle_timeout = 0;
 		ohci_work(ohci);
 	}
 
@@ -384,6 +385,16 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
 			break;
 		}
 		fallthrough;
+	case ED_OPER:		/* check for delayed unlinking */
+		if (list_empty(&ed->td_list) && ed->idle_timeout) {
+			/* ED marked for delayed unlinking, unlink it now */
+			ed->idle_timeout = 0;
+			start_ed_unlink(ohci, ed);
+			spin_unlock_irqrestore (&ohci->lock, flags);
+			schedule_timeout_uninterruptible(1);
+			goto rescan;
+		}
+		fallthrough;
 	default:
 		/* caller was supposed to have unlinked any requests;
 		 * that's not our job.  can't recover; must leak ed.
@@ -795,6 +806,13 @@ static void io_watchdog_func(struct timer_list *t)
 			}
 		}
 
+		/* Check for idle EDs that have timed out and unlink them to prevent memory leaks */
+		if (ed->state == ED_OPER && list_empty(&ed->td_list) &&
+		    ed->idle_timeout && time_after(jiffies, ed->idle_timeout)) {
+			ed->idle_timeout = 0;
+			start_ed_unlink(ohci, ed);
+		}
+
 		/* Starting from the latest pending TD, */
 		td = ed->pending_td;
 
diff --git a/drivers/usb/host/ohci-q.c b/drivers/usb/host/ohci-q.c
index 3b445312b..1df57a454 100644
--- a/drivers/usb/host/ohci-q.c
+++ b/drivers/usb/host/ohci-q.c
@@ -433,6 +433,7 @@ static struct ed *ed_get (
 		ed->hwTailP = cpu_to_hc32 (ohci, td->td_dma);
 		ed->hwHeadP = ed->hwTailP;	/* ED_C, ED_H zeroed */
 		ed->state = ED_IDLE;
+		ed->idle_timeout = 0;
 
 		is_out = !(ep->desc.bEndpointAddress & USB_DIR_IN);
 
@@ -603,6 +604,9 @@ static void td_submit_urb (
 	int		i, this_sg_len, n;
 	struct scatterlist	*sg;
 
+	/* Clear idle timeout since we're adding new TDs */
+	urb_priv->ed->idle_timeout = 0;
+
 	/* OHCI handles the bulk/interrupt data toggles itself.  We just
 	 * use the device toggle bits for resetting, and rely on the fact
 	 * that resetting toggle is meaningless if the endpoint is active.
@@ -1162,10 +1166,15 @@ static void takeback_td(struct ohci_hcd *ohci, struct td *td)
 	if (urb_priv->td_cnt >= urb_priv->length)
 		finish_urb(ohci, urb, status);
 
-	/* clean schedule:  unlink EDs that are no longer busy */
+	/* clean schedule: delay unlinking EDs to avoid SOF synchronization overhead */
 	if (list_empty(&ed->td_list)) {
-		if (ed->state == ED_OPER)
-			start_ed_unlink(ohci, ed);
+		if (ed->state == ED_OPER) {
+			/* Mark ED as idle but don't unlink immediately to avoid
+			 * 1ms SOF synchronization delays on rapid consecutive transfers.
+			 * Watchdog will clean up after 10ms if truly idle.
+			 */
+			ed->idle_timeout = jiffies + msecs_to_jiffies(10);
+		}
 
 	/* ... reenabling halted EDs only after fault cleanup */
 	} else if ((ed->hwINFO & cpu_to_hc32(ohci, ED_SKIP | ED_DEQUEUE))
diff --git a/drivers/usb/host/ohci.h b/drivers/usb/host/ohci.h
index 631dda617..858c7bebe 100644
--- a/drivers/usb/host/ohci.h
+++ b/drivers/usb/host/ohci.h
@@ -75,6 +75,7 @@ struct ed {
 #define	OKAY_TO_TAKEBACK(ohci, ed)			\
 		((int) (ohci->wdh_cnt - ed->takeback_wdh_cnt) >= 0)
 
+	unsigned long		idle_timeout;	/* when ED became idle (jiffies) */
 } __attribute__ ((aligned(16)));
 
 #define ED_MASK	((u32)~0x0f)		/* strip hw status in low addr bits */
-- 
2.51.0

Re: [PATCH] usb: ohci: delay endpoint descriptor unlinking to reduce transfer latency

[Alan Stern]

On Mon, Sep 22, 2025 at 05:48:48PM +0300, ValdikSS wrote:
> The current OHCI implementation immediately unlinks Endpoint Descriptors (EDs)
> when they become idle. Unlinking process waits for the next Start of Frame (SOF)
> interrupt as a synchronization primitive before unlinking it.
> 
> This adds ~1ms latency per transfer cycle for rapid bidirectional communication
> which leads to half the USB 1.1 speed for smaller packets at best.
> 
> When a transfer completes, takeback_td() immediately calls start_ed_unlink()
> if the ED has no more TDs queued. This triggers:
> 1. ED marked for unlinking with SOF interrupt enabled
> 2. Wait for next 1ms frame boundary (SOF interrupt)
> 3. finish_unlinks() processes the ED removal
> 
> This patch adds 275+10 ms timeout to the idle EDs. If new transfers
> arrive on the same ED before timeout expiry, clear the timeout and continue
> using the ED. Only unlink EDs that remain idle after the timeout period
> are cleared by the existing I/O watchdog, which runs every 275 ms (and
> the ED timeout is 10 ms).
> 
> This eliminates SOF synchronization delays for consecutive transfers,
> but preserves the one-frame unlinking delay which was added as a
> race condition elimination measure before the modern git history
> in commit 961c380cef (March 2004) by David Brownell.
> 
> Performance Impact:
> Tested on Orange Pi Zero3 (Allwinner H618) with Canon LBP1120 printer:
> - Before: 1.984ms average latency (write-read pattern)
> - After:  0.981ms average latency
> 
> Link: https://lore.kernel.org/all/9013fce0-6764-49b1-9e54-68e915e12d7c@valdikss.org.ru/T/
> ---

Took a while for me to get around to reviewing this.  Some comments are 
included inline below.

>  drivers/usb/host/ohci-hcd.c | 18 ++++++++++++++++++
>  drivers/usb/host/ohci-q.c   | 15 ++++++++++++---
>  drivers/usb/host/ohci.h     |  1 +
>  3 files changed, 31 insertions(+), 3 deletions(-)
> 
> diff --git a/drivers/usb/host/ohci-hcd.c b/drivers/usb/host/ohci-hcd.c
> index 9c7f30086..daaa03dd6 100644
> --- a/drivers/usb/host/ohci-hcd.c
> +++ b/drivers/usb/host/ohci-hcd.c
> @@ -364,6 +364,7 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
>  	if (ohci->rh_state != OHCI_RH_RUNNING) {
>  sanitize:
>  		ed->state = ED_IDLE;
> +		ed->idle_timeout = 0;
>  		ohci_work(ohci);
>  	}
>  
> @@ -384,6 +385,16 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
>  			break;
>  		}
>  		fallthrough;
> +	case ED_OPER:		/* check for delayed unlinking */
> +		if (list_empty(&ed->td_list) && ed->idle_timeout) {

Instead of adding these list_empty() tests, you can rely on the 
invariant that ed->idle_timeout is always 0 whenever ed->td_list is 
non-empty.

> +			/* ED marked for delayed unlinking, unlink it now */
> +			ed->idle_timeout = 0;

This isn't needed.  start_ed_unlink() calls ed_deschedule(), which sets 
ed->state to ED_UNLINK, so ed->idle_timeout will be ignored later on.

> +			start_ed_unlink(ohci, ed);
> +			spin_unlock_irqrestore (&ohci->lock, flags);
> +			schedule_timeout_uninterruptible(1);
> +			goto rescan;
> +		}
> +		fallthrough;
>  	default:
>  		/* caller was supposed to have unlinked any requests;
>  		 * that's not our job.  can't recover; must leak ed.
> @@ -795,6 +806,13 @@ static void io_watchdog_func(struct timer_list *t)
>  			}
>  		}
>  
> +		/* Check for idle EDs that have timed out and unlink them to prevent memory leaks */
> +		if (ed->state == ED_OPER && list_empty(&ed->td_list) &&
> +		    ed->idle_timeout && time_after(jiffies, ed->idle_timeout)) {
> +			ed->idle_timeout = 0;
> +			start_ed_unlink(ohci, ed);

Again, the list_empty() test and setting ed->idle_timeout to 0 aren't 
needed.

> +		}
> +
>  		/* Starting from the latest pending TD, */
>  		td = ed->pending_td;
>  
> diff --git a/drivers/usb/host/ohci-q.c b/drivers/usb/host/ohci-q.c
> index 3b445312b..1df57a454 100644
> --- a/drivers/usb/host/ohci-q.c
> +++ b/drivers/usb/host/ohci-q.c
> @@ -433,6 +433,7 @@ static struct ed *ed_get (
>  		ed->hwTailP = cpu_to_hc32 (ohci, td->td_dma);
>  		ed->hwHeadP = ed->hwTailP;	/* ED_C, ED_H zeroed */
>  		ed->state = ED_IDLE;
> +		ed->idle_timeout = 0;

Not needed since the memory allocated in ed_alloc() is zeroed.

>  
>  		is_out = !(ep->desc.bEndpointAddress & USB_DIR_IN);
>  
> @@ -603,6 +604,9 @@ static void td_submit_urb (
>  	int		i, this_sg_len, n;
>  	struct scatterlist	*sg;
>  
> +	/* Clear idle timeout since we're adding new TDs */
> +	urb_priv->ed->idle_timeout = 0;
> +
>  	/* OHCI handles the bulk/interrupt data toggles itself.  We just
>  	 * use the device toggle bits for resetting, and rely on the fact
>  	 * that resetting toggle is meaningless if the endpoint is active.
> @@ -1162,10 +1166,15 @@ static void takeback_td(struct ohci_hcd *ohci, struct td *td)
>  	if (urb_priv->td_cnt >= urb_priv->length)
>  		finish_urb(ohci, urb, status);
>  
> -	/* clean schedule:  unlink EDs that are no longer busy */
> +	/* clean schedule: delay unlinking EDs to avoid SOF synchronization overhead */
>  	if (list_empty(&ed->td_list)) {
> -		if (ed->state == ED_OPER)
> -			start_ed_unlink(ohci, ed);
> +		if (ed->state == ED_OPER) {
> +			/* Mark ED as idle but don't unlink immediately to avoid
> +			 * 1ms SOF synchronization delays on rapid consecutive transfers.
> +			 * Watchdog will clean up after 10ms if truly idle.
> +			 */
> +			ed->idle_timeout = jiffies + msecs_to_jiffies(10);

It would be a good idea to add:

			ed->idle_timeout += !ed->idle_timeout;

to handle the case where jiffies + msecs_to_jiffies(10) just happens to 
roll over to 0.

> +		}
>  
>  	/* ... reenabling halted EDs only after fault cleanup */
>  	} else if ((ed->hwINFO & cpu_to_hc32(ohci, ED_SKIP | ED_DEQUEUE))
> diff --git a/drivers/usb/host/ohci.h b/drivers/usb/host/ohci.h
> index 631dda617..858c7bebe 100644
> --- a/drivers/usb/host/ohci.h
> +++ b/drivers/usb/host/ohci.h
> @@ -75,6 +75,7 @@ struct ed {
>  #define	OKAY_TO_TAKEBACK(ohci, ed)			\
>  		((int) (ohci->wdh_cnt - ed->takeback_wdh_cnt) >= 0)
>  
> +	unsigned long		idle_timeout;	/* when ED became idle (jiffies) */
>  } __attribute__ ((aligned(16)));
>  
>  #define ED_MASK	((u32)~0x0f)		/* strip hw status in low addr bits */

Overall this looks very good.

Alan Stern

[PATCH v2] usb: ohci: delay endpoint descriptor unlinking to reduce transfer latency

[ValdikSS]

The current OHCI implementation immediately unlinks Endpoint Descriptors
(EDs) when they become idle. Unlinking process waits for the next Start
of Frame (SOF) interrupt as a synchronization primitive before unlinking
it.

This adds ~1ms latency per transfer cycle for rapid bidirectional
communication which leads to half the USB 1.1 speed for smaller packets
at best.

When a transfer completes, takeback_td() immediately calls
start_ed_unlink() if the ED has no more TDs queued. This triggers:
1. ED marked for unlinking with SOF interrupt enabled
2. Wait for next 1ms frame boundary (SOF interrupt)
3. finish_unlinks() processes the ED removal

This patch adds 275+10 ms timeout to the idle EDs. If new transfers
arrive on the same ED before timeout expiry, clear the timeout and
continue using the ED. Only EDs that remain idle after the timeout
period are cleared by the existing I/O watchdog, which runs every
275 ms (and the ED timeout is 10 ms).

This eliminates SOF synchronization delays for consecutive transfers,
but preserves the one-frame unlinking delay which was added as a race
condition elimination measure before the modern git history in
commit 961c380cef (March 2004) by David Brownell.

Performance Impact:
Tested on Orange Pi Zero3 (Allwinner H618) with Canon LBP1120 printer:
- Before: 1.984ms average latency (write-read pattern)
- After:  0.981ms average latency

Link: https://lore.kernel.org/all/9013fce0-6764-49b1-9e54-68e915e12d7c@valdikss.org.ru/T/
Signed-off-by: ValdikSS <iam@valdikss.org.ru>
---
v1 -> v2: removed redundant list_empty() checks and idle_timeout=0 assignment,
          ensured idle_timeout jiffy to be non-zero.
Thanks Alan!
---
 drivers/usb/host/ohci-hcd.c | 15 +++++++++++++++
 drivers/usb/host/ohci-q.c   | 15 ++++++++++++---
 drivers/usb/host/ohci.h     |  1 +
 3 files changed, 28 insertions(+), 3 deletions(-)

diff --git a/drivers/usb/host/ohci-hcd.c b/drivers/usb/host/ohci-hcd.c
index 9c7f30086..e89c9daec 100644
--- a/drivers/usb/host/ohci-hcd.c
+++ b/drivers/usb/host/ohci-hcd.c
@@ -364,6 +364,7 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
 	if (ohci->rh_state != OHCI_RH_RUNNING) {
 sanitize:
 		ed->state = ED_IDLE;
+		ed->idle_timeout = 0;
 		ohci_work(ohci);
 	}
 
@@ -384,6 +385,15 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
 			break;
 		}
 		fallthrough;
+	case ED_OPER:		/* check for delayed unlinking */
+		if (ed->idle_timeout) {
+			/* ED marked for delayed unlinking, unlink it now */
+			start_ed_unlink(ohci, ed);
+			spin_unlock_irqrestore(&ohci->lock, flags);
+			schedule_timeout_uninterruptible(1);
+			goto rescan;
+		}
+		fallthrough;
 	default:
 		/* caller was supposed to have unlinked any requests;
 		 * that's not our job.  can't recover; must leak ed.
@@ -795,6 +805,11 @@ static void io_watchdog_func(struct timer_list *t)
 			}
 		}
 
+		/* Check for idle EDs that have timed out and unlink them to prevent memory leaks */
+		if (ed->state == ED_OPER && ed->idle_timeout &&
+				time_after(jiffies, ed->idle_timeout))
+			start_ed_unlink(ohci, ed);
+
 		/* Starting from the latest pending TD, */
 		td = ed->pending_td;
 
diff --git a/drivers/usb/host/ohci-q.c b/drivers/usb/host/ohci-q.c
index 3b445312b..e0725e490 100644
--- a/drivers/usb/host/ohci-q.c
+++ b/drivers/usb/host/ohci-q.c
@@ -603,6 +603,9 @@ static void td_submit_urb (
 	int		i, this_sg_len, n;
 	struct scatterlist	*sg;
 
+	/* Clear idle timeout since we're adding new TDs */
+	urb_priv->ed->idle_timeout = 0;
+
 	/* OHCI handles the bulk/interrupt data toggles itself.  We just
 	 * use the device toggle bits for resetting, and rely on the fact
 	 * that resetting toggle is meaningless if the endpoint is active.
@@ -1162,10 +1165,16 @@ static void takeback_td(struct ohci_hcd *ohci, struct td *td)
 	if (urb_priv->td_cnt >= urb_priv->length)
 		finish_urb(ohci, urb, status);
 
-	/* clean schedule:  unlink EDs that are no longer busy */
+	/* clean schedule: delay unlinking EDs to avoid SOF synchronization overhead */
 	if (list_empty(&ed->td_list)) {
-		if (ed->state == ED_OPER)
-			start_ed_unlink(ohci, ed);
+		if (ed->state == ED_OPER) {
+			/* Mark ED as idle but don't unlink immediately to avoid
+			 * 1ms SOF synchronization delays on rapid consecutive transfers.
+			 * Watchdog will clean up after 10ms if truly idle.
+			 */
+			ed->idle_timeout = jiffies + msecs_to_jiffies(10);
+			ed->idle_timeout += !ed->idle_timeout;
+		}
 
 	/* ... reenabling halted EDs only after fault cleanup */
 	} else if ((ed->hwINFO & cpu_to_hc32(ohci, ED_SKIP | ED_DEQUEUE))
diff --git a/drivers/usb/host/ohci.h b/drivers/usb/host/ohci.h
index 631dda617..858c7bebe 100644
--- a/drivers/usb/host/ohci.h
+++ b/drivers/usb/host/ohci.h
@@ -75,6 +75,7 @@ struct ed {
 #define	OKAY_TO_TAKEBACK(ohci, ed)			\
 		((int) (ohci->wdh_cnt - ed->takeback_wdh_cnt) >= 0)
 
+	unsigned long		idle_timeout;	/* when ED became idle (jiffies) */
 } __attribute__ ((aligned(16)));
 
 #define ED_MASK	((u32)~0x0f)		/* strip hw status in low addr bits */
-- 
2.51.0

Re: [PATCH v2] usb: ohci: delay endpoint descriptor unlinking to reduce transfer latency

[Alan Stern]

On Thu, Oct 02, 2025 at 01:34:42AM +0300, ValdikSS wrote:
> The current OHCI implementation immediately unlinks Endpoint Descriptors
> (EDs) when they become idle. Unlinking process waits for the next Start
> of Frame (SOF) interrupt as a synchronization primitive before unlinking
> it.
> 
> This adds ~1ms latency per transfer cycle for rapid bidirectional
> communication which leads to half the USB 1.1 speed for smaller packets
> at best.
> 
> When a transfer completes, takeback_td() immediately calls
> start_ed_unlink() if the ED has no more TDs queued. This triggers:
> 1. ED marked for unlinking with SOF interrupt enabled
> 2. Wait for next 1ms frame boundary (SOF interrupt)
> 3. finish_unlinks() processes the ED removal
> 
> This patch adds 275+10 ms timeout to the idle EDs. If new transfers
> arrive on the same ED before timeout expiry, clear the timeout and
> continue using the ED. Only EDs that remain idle after the timeout
> period are cleared by the existing I/O watchdog, which runs every
> 275 ms (and the ED timeout is 10 ms).
> 
> This eliminates SOF synchronization delays for consecutive transfers,
> but preserves the one-frame unlinking delay which was added as a race
> condition elimination measure before the modern git history in
> commit 961c380cef (March 2004) by David Brownell.
> 
> Performance Impact:
> Tested on Orange Pi Zero3 (Allwinner H618) with Canon LBP1120 printer:
> - Before: 1.984ms average latency (write-read pattern)
> - After:  0.981ms average latency
> 
> Link: https://lore.kernel.org/all/9013fce0-6764-49b1-9e54-68e915e12d7c@valdikss.org.ru/T/
> Signed-off-by: ValdikSS <iam@valdikss.org.ru>
> ---
> v1 -> v2: removed redundant list_empty() checks and idle_timeout=0 assignment,
>           ensured idle_timeout jiffy to be non-zero.
> Thanks Alan!
> ---

Reviewed-by: Alan Stern <stern@rowland.harvard.edu>

Looks good!  Greg won't accept it until the current merge window closes 
(about a week and a half), but he'll keep it in the queue until then.

Alan Stern

>  drivers/usb/host/ohci-hcd.c | 15 +++++++++++++++
>  drivers/usb/host/ohci-q.c   | 15 ++++++++++++---
>  drivers/usb/host/ohci.h     |  1 +
>  3 files changed, 28 insertions(+), 3 deletions(-)
> 
> diff --git a/drivers/usb/host/ohci-hcd.c b/drivers/usb/host/ohci-hcd.c
> index 9c7f30086..e89c9daec 100644
> --- a/drivers/usb/host/ohci-hcd.c
> +++ b/drivers/usb/host/ohci-hcd.c
> @@ -364,6 +364,7 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
>  	if (ohci->rh_state != OHCI_RH_RUNNING) {
>  sanitize:
>  		ed->state = ED_IDLE;
> +		ed->idle_timeout = 0;
>  		ohci_work(ohci);
>  	}
>  
> @@ -384,6 +385,15 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
>  			break;
>  		}
>  		fallthrough;
> +	case ED_OPER:		/* check for delayed unlinking */
> +		if (ed->idle_timeout) {
> +			/* ED marked for delayed unlinking, unlink it now */
> +			start_ed_unlink(ohci, ed);
> +			spin_unlock_irqrestore(&ohci->lock, flags);
> +			schedule_timeout_uninterruptible(1);
> +			goto rescan;
> +		}
> +		fallthrough;
>  	default:
>  		/* caller was supposed to have unlinked any requests;
>  		 * that's not our job.  can't recover; must leak ed.
> @@ -795,6 +805,11 @@ static void io_watchdog_func(struct timer_list *t)
>  			}
>  		}
>  
> +		/* Check for idle EDs that have timed out and unlink them to prevent memory leaks */
> +		if (ed->state == ED_OPER && ed->idle_timeout &&
> +				time_after(jiffies, ed->idle_timeout))
> +			start_ed_unlink(ohci, ed);
> +
>  		/* Starting from the latest pending TD, */
>  		td = ed->pending_td;
>  
> diff --git a/drivers/usb/host/ohci-q.c b/drivers/usb/host/ohci-q.c
> index 3b445312b..e0725e490 100644
> --- a/drivers/usb/host/ohci-q.c
> +++ b/drivers/usb/host/ohci-q.c
> @@ -603,6 +603,9 @@ static void td_submit_urb (
>  	int		i, this_sg_len, n;
>  	struct scatterlist	*sg;
>  
> +	/* Clear idle timeout since we're adding new TDs */
> +	urb_priv->ed->idle_timeout = 0;
> +
>  	/* OHCI handles the bulk/interrupt data toggles itself.  We just
>  	 * use the device toggle bits for resetting, and rely on the fact
>  	 * that resetting toggle is meaningless if the endpoint is active.
> @@ -1162,10 +1165,16 @@ static void takeback_td(struct ohci_hcd *ohci, struct td *td)
>  	if (urb_priv->td_cnt >= urb_priv->length)
>  		finish_urb(ohci, urb, status);
>  
> -	/* clean schedule:  unlink EDs that are no longer busy */
> +	/* clean schedule: delay unlinking EDs to avoid SOF synchronization overhead */
>  	if (list_empty(&ed->td_list)) {
> -		if (ed->state == ED_OPER)
> -			start_ed_unlink(ohci, ed);
> +		if (ed->state == ED_OPER) {
> +			/* Mark ED as idle but don't unlink immediately to avoid
> +			 * 1ms SOF synchronization delays on rapid consecutive transfers.
> +			 * Watchdog will clean up after 10ms if truly idle.
> +			 */
> +			ed->idle_timeout = jiffies + msecs_to_jiffies(10);
> +			ed->idle_timeout += !ed->idle_timeout;
> +		}
>  
>  	/* ... reenabling halted EDs only after fault cleanup */
>  	} else if ((ed->hwINFO & cpu_to_hc32(ohci, ED_SKIP | ED_DEQUEUE))
> diff --git a/drivers/usb/host/ohci.h b/drivers/usb/host/ohci.h
> index 631dda617..858c7bebe 100644
> --- a/drivers/usb/host/ohci.h
> +++ b/drivers/usb/host/ohci.h
> @@ -75,6 +75,7 @@ struct ed {
>  #define	OKAY_TO_TAKEBACK(ohci, ed)			\
>  		((int) (ohci->wdh_cnt - ed->takeback_wdh_cnt) >= 0)
>  
> +	unsigned long		idle_timeout;	/* when ED became idle (jiffies) */
>  } __attribute__ ((aligned(16)));
>  
>  #define ED_MASK	((u32)~0x0f)		/* strip hw status in low addr bits */
> -- 
> 2.51.0
> 

[PATCH v2 RESEND] usb: ohci: delay endpoint descriptor unlinking to reduce transfer latency

[ValdikSS]

The current OHCI implementation immediately unlinks Endpoint Descriptors
(EDs) when they become idle. Unlinking process waits for the next Start
of Frame (SOF) interrupt as a synchronization primitive before unlinking
it.

This adds ~1ms latency per transfer cycle for rapid bidirectional
communication which leads to half the USB 1.1 speed for smaller packets
at best.

When a transfer completes, takeback_td() immediately calls
start_ed_unlink() if the ED has no more TDs queued. This triggers:
1. ED marked for unlinking with SOF interrupt enabled
2. Wait for next 1ms frame boundary (SOF interrupt)
3. finish_unlinks() processes the ED removal

This patch adds 275+10 ms timeout to the idle EDs. If new transfers
arrive on the same ED before timeout expiry, clear the timeout and
continue using the ED. Only EDs that remain idle after the timeout
period are cleared by the existing I/O watchdog, which runs every
275 ms (and the ED timeout is 10 ms).

This eliminates SOF synchronization delays for consecutive transfers,
but preserves the one-frame unlinking delay which was added as a race
condition elimination measure before the modern git history in
commit 961c380cef (March 2004) by David Brownell.

Performance Impact:
Tested on Orange Pi Zero3 (Allwinner H618) with Canon LBP1120 printer:
- Before: 1.984ms average latency (write-read pattern)
- After:  0.981ms average latency

Link: https://lore.kernel.org/all/9013fce0-6764-49b1-9e54-68e915e12d7c@valdikss.org.ru/T/
Signed-off-by: ValdikSS <iam@valdikss.org.ru>
Reviewed-by: Alan Stern <stern@rowland.harvard.edu>
---
 drivers/usb/host/ohci-hcd.c | 15 +++++++++++++++
 drivers/usb/host/ohci-q.c   | 15 ++++++++++++---
 drivers/usb/host/ohci.h     |  1 +
 3 files changed, 28 insertions(+), 3 deletions(-)

diff --git a/drivers/usb/host/ohci-hcd.c b/drivers/usb/host/ohci-hcd.c
index 9c7f30086..e89c9daec 100644
--- a/drivers/usb/host/ohci-hcd.c
+++ b/drivers/usb/host/ohci-hcd.c
@@ -364,6 +364,7 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
 	if (ohci->rh_state != OHCI_RH_RUNNING) {
 sanitize:
 		ed->state = ED_IDLE;
+		ed->idle_timeout = 0;
 		ohci_work(ohci);
 	}
 
@@ -384,6 +385,15 @@ ohci_endpoint_disable (struct usb_hcd *hcd, struct usb_host_endpoint *ep)
 			break;
 		}
 		fallthrough;
+	case ED_OPER:		/* check for delayed unlinking */
+		if (ed->idle_timeout) {
+			/* ED marked for delayed unlinking, unlink it now */
+			start_ed_unlink(ohci, ed);
+			spin_unlock_irqrestore(&ohci->lock, flags);
+			schedule_timeout_uninterruptible(1);
+			goto rescan;
+		}
+		fallthrough;
 	default:
 		/* caller was supposed to have unlinked any requests;
 		 * that's not our job.  can't recover; must leak ed.
@@ -795,6 +805,11 @@ static void io_watchdog_func(struct timer_list *t)
 			}
 		}
 
+		/* Check for idle EDs that have timed out and unlink them to prevent memory leaks */
+		if (ed->state == ED_OPER && ed->idle_timeout &&
+				time_after(jiffies, ed->idle_timeout))
+			start_ed_unlink(ohci, ed);
+
 		/* Starting from the latest pending TD, */
 		td = ed->pending_td;
 
diff --git a/drivers/usb/host/ohci-q.c b/drivers/usb/host/ohci-q.c
index 3b445312b..e0725e490 100644
--- a/drivers/usb/host/ohci-q.c
+++ b/drivers/usb/host/ohci-q.c
@@ -603,6 +603,9 @@ static void td_submit_urb (
 	int		i, this_sg_len, n;
 	struct scatterlist	*sg;
 
+	/* Clear idle timeout since we're adding new TDs */
+	urb_priv->ed->idle_timeout = 0;
+
 	/* OHCI handles the bulk/interrupt data toggles itself.  We just
 	 * use the device toggle bits for resetting, and rely on the fact
 	 * that resetting toggle is meaningless if the endpoint is active.
@@ -1162,10 +1165,16 @@ static void takeback_td(struct ohci_hcd *ohci, struct td *td)
 	if (urb_priv->td_cnt >= urb_priv->length)
 		finish_urb(ohci, urb, status);
 
-	/* clean schedule:  unlink EDs that are no longer busy */
+	/* clean schedule: delay unlinking EDs to avoid SOF synchronization overhead */
 	if (list_empty(&ed->td_list)) {
-		if (ed->state == ED_OPER)
-			start_ed_unlink(ohci, ed);
+		if (ed->state == ED_OPER) {
+			/* Mark ED as idle but don't unlink immediately to avoid
+			 * 1ms SOF synchronization delays on rapid consecutive transfers.
+			 * Watchdog will clean up after 10ms if truly idle.
+			 */
+			ed->idle_timeout = jiffies + msecs_to_jiffies(10);
+			ed->idle_timeout += !ed->idle_timeout;
+		}
 
 	/* ... reenabling halted EDs only after fault cleanup */
 	} else if ((ed->hwINFO & cpu_to_hc32(ohci, ED_SKIP | ED_DEQUEUE))
diff --git a/drivers/usb/host/ohci.h b/drivers/usb/host/ohci.h
index 631dda617..858c7bebe 100644
--- a/drivers/usb/host/ohci.h
+++ b/drivers/usb/host/ohci.h
@@ -75,6 +75,7 @@ struct ed {
 #define	OKAY_TO_TAKEBACK(ohci, ed)			\
 		((int) (ohci->wdh_cnt - ed->takeback_wdh_cnt) >= 0)
 
+	unsigned long		idle_timeout;	/* when ED became idle (jiffies) */
 } __attribute__ ((aligned(16)));
 
 #define ED_MASK	((u32)~0x0f)		/* strip hw status in low addr bits */
-- 
2.51.0