libusb backend: attempt to fix DRAIN_OUTPUT race condition. Fixes #1461

[ValdikSS]

CUPS_SC_CMD_DRAIN_OUTPUT sidechannel command is supposed to ensure that all the data sent by the filter would be consumed by the backend and sent to the printer via USB before it returns.

However, if backend's main thread read and processed filter's data before filter managed to send CUPS_SC_CMD_DRAIN_OUTPUT, the filter will be blocked for 1 second, as backend will be blocked in select() waiting for new data (while filter is waiting for DRAIN_OUTPUT response and does not send anything).

This is a hacky attempt to fix this issue. However, it's not without flaw:
* If backend's main thread is slow and sidechannel thread is fast, the response to CUPS_SC_CMD_DRAIN_OUTPUT may be sent without actually draining (and even reading) the data.
* This means that's a tradeoff towards potentially breaking framing of some USB protocols to prevent 1-second locking (and breaking printing for timing-sensitive protocols).

A pipe is used to wake up main thread from select().

[darkvision77]

I made a test filter that spams with the no-response command 0xD0A2 (send 0xD0A2, drain, loop).
With this PR, I had two timeouts for 10k iterations. They were caused by the fact that in print_device(), the response to the command occurs first, and only then the g.drain_output flag is removed:

cups/backend/usb-libusb.c

Lines 425 to 430 in 07c17a0

	if (g.drain_output && !nfds && !g.print_bytes)
	{
	/* Send a response... */
	cupsSideChannelWrite(CUPS_SC_CMD_DRAIN_OUTPUT, CUPS_SC_STATUS_OK, NULL, 0, 1.0);
	g.drain_output = 0;
	}

It means that the backend sends a response to drain, the filter receives it, sends new data and another drain, which is processed by sidechannel_thread(), which sets the flag g.drain_output to 1, and only then print_device() resets g.drain_output to 0, leaving new drain command without a response.

I would use some synchronization primitives, but this also works:

 if (g.drain_output && !nfds && !g.print_bytes)
 {
+    g.drain_output = 0;
     /* Send a response... */
     cupsSideChannelWrite(CUPS_SC_CMD_DRAIN_OUTPUT, CUPS_SC_STATUS_OK, NULL, 0, 1.0);
-    g.drain_output = 0;
 }

Also, currently, the backend first responds to drain cmd and only then reads print_fd. With the previous commit, there were many situations when the filter managed to send another packet before the backend read print_fd.
There are no problems with the last commit, but in theory, such behavior is possible.

Except for the order of setting g.drain_output, everything works perfectly!

[ValdikSS]

Also, currently, the backend first responds to drain cmd and only then reads print_fd.

I'm not exactly sure, because after my changes the check check for nfds

cups/backend/usb-libusb.c

Lines 422 to 427 in c5ce534

	if (g.drain_output && !nfds && !g.print_bytes)
	{
	/* Send a response... */
	cupsSideChannelWrite(CUPS_SC_CMD_DRAIN_OUTPUT, CUPS_SC_STATUS_OK, NULL, 0, 1.0);
	g.drain_output = 0;
	}

will not work the way it used to work: nfds will be set if sidechannel thread woke up the main thread while it was in select, and DRAIN flag will not be removed until everything is read from the fd (will be removed only on next loop iteration). I might be wrong though.

[ValdikSS]

Does it work flawlessly for you with g.drain_output = 0; on top?

[ValdikSS]

Just moved the response after reading the print_fd, please test the current MR draft.

[ValdikSS]

Maybe move it even later, after the data has been sent to the printer and not just read from the fd?

[darkvision77]

I'm not exactly sure, because after my changes the check check for nfds

Well... Forget everything I said about the filter having time to send before read(print_fd).
I double-checked, and in that version, to eliminate most of the problems, I not only moved the command response block down, but also changed the condition.
In the current version, the nfds check does actually work properly and no changes are required.
So there's no need to move anything.

Does it work flawlessly for you with g.drain_output = 0; on top?

Yep.