winebus.sys: Device reports coming in too fast, last report not read yet

[Kai Krakow]

Hello!

I'm currently exploring the massive amounts of the following error
messages I see when using my xbox controller:

002b:err:hid_report:process_hid_report Device reports coming in too
fast, last report not read yet!
002b:err:hid_report:process_hid_report Device reports coming in too
fast, last report not read yet!
002b:err:hid_report:process_hid_report Device reports coming in too
fast, last report not read yet!
[...]

The code that generates this looks a bit problematic to me.

First, it's definitely loosing HID reports here. I wonder if this also
explains why my controller rarely sees missing button presses. But the
issue seen here seems to mostly result from the controller generating
lots and lots of axis events.

So my first thought was: Hey, if there's a buffer overrun issue then
why not just replace axis reports in the buffer with the most current
report for the same axes so we do not easily overwrite button reports.
But looking at the code I found that there is no buffering at all. It
just unconditionally overwrites the last report (writing that error
message if that report was not read yet), and then continues to a
while loop I do not understand at all.

@@@ void process_hid_report(DEVICE_OBJECT *device, BYTE *report, DWORD length)
> if (!ext->last_report_read)
>     ERR_(hid_report)("Device reports coming in too fast, last report not read yet!\n");

> memcpy(ext->last_report, report, length);
> ext->last_report_size = length;
> ext->last_report_read = FALSE;

> while ((entry = RemoveHeadList(&ext->irp_queue)) != &ext->irp_queue)
> {
>     IO_STACK_LOCATION *irpsp;
>     TRACE_(hid_report)("Processing Request\n");
>     irp = CONTAINING_RECORD(entry, IRP, Tail.Overlay.s.ListEntry);
>     irpsp = IoGetCurrentIrpStackLocation(irp);
>     irp->IoStatus.u.Status = deliver_last_report(ext,
>         irpsp->Parameters.DeviceIoControl.OutputBufferLength,
>         irp->UserBuffer, &irp->IoStatus.Information);
>     ext->last_report_read = TRUE;
>     IoCompleteRequest(irp, IO_NO_INCREMENT);
> }

Why doesn't the while loop run before replacing the last report so it
has a chance to deliver the buffered report before overwriting it? Of
course the while loop would still be needed after replacing the report
so it would make sense to put it into a helper.

Second, I also wonder: Doesn't the while loop potentially run more
than one loop? Wouldn't it then deliver just the same last report
multiple times? Where is the point in this? This would also conflict
with my idea of trying to deliver the last report again before
replacing it, doesn't it? What's the IRP queue anyway? Is it part of a
consumer or producer?

Thus, my current understanding it that first, it looses reports, and
second, it duplicates reports if it lost some before.


I see that process_hid_report() is called from the lower SDL layers in
my case. Does it make sense to handle buffering there? Apparently,
process_hid_report() doesn't return a result, so there's no feedback
whether the HID report could deliver the report or not. Would it make
sense to return the result of ext->last_report_read? That way, the SDL
layer could buffer the report itself and maybe implement some logic to
reduce the amount of axis reports generated. For axis reports from the
joysticks, it doesn't matter if we overwrite reports as axis position
is reported as an absolute value. So we could keep one buffer per axis
and keep track of whether it was delivered or not, then retry next
time. But this should probably go into some thread which keeps on
trying to process such buffered hid reports.


Thanks,
Kai