Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
On 09/14/2015 02:03 PM, Fabian Greffrath wrote: Am Montag, den 14.09.2015, 13:49 -0300 schrieb Till Kamppeter: The fix I have backported to said cups release. Fine, but why have you set yourself as Author for the patch? - Fabian Corrected in Debian GIT repo. Sorry. Till
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
On 09/14/2015 02:03 PM, Fabian Greffrath wrote: Am Montag, den 14.09.2015, 13:49 -0300 schrieb Till Kamppeter: The fix I have backported to said cups release. Fine, but why have you set yourself as Author for the patch? - Fabian Sorry, cut-and-paste error, I have copied the header of another patch and edited the field but forgot that the "Author" field needs to be edited, too, should get changed to Mike Sweet. Till
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
Am Montag, den 14.09.2015, 13:49 -0300 schrieb Till Kamppeter: > The fix I have backported to said cups release. Fine, but why have you set yourself as Author for the patch? - Fabian signature.asc Description: This is a digitally signed message part
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
This is fixed now in cups 2.1.0-3. It is the following upstream bug report: https://www.cups.org/str.php?L4707 The fix I have backported to said cups release. Till
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
Control: forwarded -1 https://www.cups.org/str.php?L4707 signature.asc Description: This is a digitally signed message part
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
Am Donnerstag, den 09.07.2015, 14:11 +0100 schrieb Brian Potkin: > The word "sometimes" isn't one which brings joy to the heart when bug > hunting. :) In this context, I suspect that "sometimes" is related to Windows 7 running (or not) as a guest system in VirtualBox and trying to access the USB ports of my host system which is running Debian and thus cups. - Fabian signature.asc Description: This is a digitally signed message part
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
Control: tags -1 + patch upstream Hi again, Am Donnerstag, den 09.07.2015, 16:53 +0200 schrieb Fabian Greffrath: > Thus, I assume that the following patch might work, but i am not sure > yet, because, you know, it only happens "sometimes". ;) now I have proof that it works! My printing was hanging again today, with the "usb" process eating up 100% CPU. It's process ID was 24901 and so I attached GDB to it. Look what happened: $ sudo gdb /usr/lib/cups/backend-available/usb --pid 24901 [...] (gdb) bt #0 0x7f7884939c17 in ioctl () at ../sysdeps/unix/syscall-template.S:81 #1 0x7f78850ad4d1 in ?? () from /lib/x86_64-linux-gnu/libusb-1.0.so.0 #2 0x7f78850a7950 in libusb_claim_interface () from /lib/x86_64-linux-gnu/libusb-1.0.so.0 #3 0x7f78854e0ee8 in open_device (printer=0x7f78856e51c0 , verbose=1) at usb-libusb.c:1515 #4 find_device (cb=0x7f78854e0900 , data=0x7f7885e3c630) at usb-libusb.c:942 #5 0x7f78854e1a98 in print_device (uri=0x7f7885e3c630 "usb://Kyocera/FS-1120D?serial=Q5Y1358476", hostname=, resource=, options=, print_fd=0, copies=1, argc=6, argv=0x7ffd7b31d838) at usb-libusb.c:220 #6 0x7f78854df603 in main (argc=6, argv=0x7ffd7b31d838) at usb.c:248 (gdb) frame 3 #3 0x7f78854e0ee8 in open_device (printer=0x7f78856e51c0 , verbose=1) at usb-libusb.c:1515 1515usb-libusb.c: Datei oder Verzeichnis nicht gefunden. So, it was hanging in line 1515 of usb-libusb.c, just as I suspected. (gdb) p printer $1 = (usb_printer_t *) 0x7f78856e51c0 (gdb) p *printer $2 = {device = 0x7f7885e3fde0, conf = 0, origconf = 0, iface = 0, altset = 0, write_endp = 0, read_endp = 1, protocol = 2, usblp_attached = 0, reset_after_job = 0, quirks = 0, handle = 0x7f7885e43f00} This was just a test to see if the struct was still intact, all looked good. (gdb) p libusb_detach_kernel_driver(printer->handle, printer->iface)libusb_claim_interface $3 = 0 (gdb) c Continuing. And indeed, it broke the loop and printing continued! So, it makes sense to check if the error code of libusb_claim_interface() is indeed LIBUSB_ERROR_BUSY and add another call to libusb_detach_kernel_driver() if it is. I have no idea, though, why it is possible that the device is reported busy at this stage, as it is already checked earlier in the code and clearly *shouldn't* be at this point, but apparently it is possible and calling libusb_detach_kernel_driver() again is a means to fix this. Could you please take this upstream? Thank you very much! Cheers, Fabian signature.asc Description: This is a digitally signed message part
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
Am Donnerstag, den 09.07.2015, 14:11 +0100 schrieb Brian Potkin: > The word "sometimes" isn't one which brings joy to the heart when bug > hunting. :) Yes, I know, sorry. It is also confusing for me. As I wrote in one of my later follow-ups, if I "killall -9 usb" the backend, the next printing attempt may work without a flaw. thus, I suspect something like a race condition as the culprit. > How ofter does this happen? Has it just appeared with cups 2.0.3? No, it also happened with cups 1.x. I just didn't find the time and nerves to report the bug, because - just as you said - "it sometimes dosn't work" isn't a good bug description to start with. ;) > > ioctl(15, USBDEVFS_CLAIMINTERFACE, 0x7fffad353bfc) = -1 EBUSY > > (Device or resource busy) I believe that the code which causes this is the following in backend/usb-libusb.c:1515: while ((errcode = libusb_claim_interface(printer->handle, number1)) < 0) { if (errcode != LIBUSB_ERROR_BUSY) { fprintf(stderr, "DEBUG: Failed to claim interface %d for %04x:%04x: %s\n", number1, devdesc.idVendor, devdesc.idProduct, strerror(errno)); goto error; } } So, what it does is trying to claim the interface and if the error code isn't LIBUSB_ERROR_BUSY it busts out. But what if the error code actually is LIBUSB_ERROR_BUSY? then the code is dead-locked in this loop and tries to claim the interface endlessly. I think this is what I see on my system. Well, it's not that easy. Actually, LIBUSB_ERROR_BUSY is only returned if the USB interface is already claimed, e.g. by a kernel driver. This is checked earlier in the code in line 1437: If the return value of libusb_kernel_driver_active() is 1 then a kernel driver is active and libusb_detach_kernel_driver() is called. So, it should be impossible for the interface to be already claimed when the code in line 1515 is called. But, one never knows, and repeatedly calling libusb_claim_interface() over and over again won't help if the culprit is LIBUSB_ERROR_BUSY but this is never checked for. Thus, I assume that the following patch might work, but i am not sure yet, because, you know, it only happens "sometimes". ;) --- a/cups-2.0.3/backend/usb-libusb.c +++ b/home/greffrath/usb-libusb.c @@ -1522,6 +1522,16 @@ open_device(usb_printer_t *printer, /* I - Printer */ goto error; } +else if ((errcode = libusb_detach_kernel_driver(printer->handle, printer->iface)) < 0) +{ + fprintf(stderr, + "DEBUG: Failed to detach \"usblp\" module from %04x:%04x\n", + devdesc.idVendor, devdesc.idProduct); + + goto error; +} + +sleep (1); } /* I added a sleep(1) call to prevent this loop from eating up 100% cpu as it currently does. Do you think you could carry this issue and my suggested patch upstream? Thank you very much already! Cheers, Fabian signature.asc Description: This is a digitally signed message part
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
On Wed 08 Jul 2015 at 12:01:57 +0200, Fabian Greffrath wrote: > Hi there, Hi there, Fabian. Thank you for your report. > sometimes it happens that I print a file to a USB-attached printer > and instead of printing, the usb process eats up 100% cpu. Nothing > else happens, apart from some GNOME window popping up and asking if my > printer is actually connected. In fact, it is. The word "sometimes" isn't one which brings joy to the heart when bug hunting. :) How ofter does this happen? Has it just appeared with cups 2.0.3? > This is what strace says the offending process does all the time: > > ioctl(15, USBDEVFS_CLAIMINTERFACE, 0x7fffad353bfc) = -1 EBUSY (Device > or resource busy) > > This repeasts endlessly. > > Please tell me how I can provide further information. The section "Testing a Backend and a Printer" at https://wiki.debian.org/Dissecting and Debugging the CUPS Printing System gives a way of trying to determine whether or not the backend is a cause of your problem. We'll be assuming the filtering system is working ok but you might want to set up debug logging and examine the error_log for any untoward signs with filtering or sending the job to the printer. If files sent directly to printer always print without issue it would point to cups as the source of the trouble. If it helps, there is a way of setting up directly printing to the printer as part of everyday printing. It might take some of the tedium out of testing. Regards, Brian. -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org
Bug#791766: /usr/lib/cups/backend-available/usb: USB backend eats 100% CPU
Package: cups Version: 2.0.3-6 Severity: important File: /usr/lib/cups/backend-available/usb Hi there, sometimes it happens that I print a file to a USB-attached printer and instead of printing, the usb process eats up 100% cpu. Nothing else happens, apart from some GNOME window popping up and asking if my printer is actually connected. In fact, it is. This is what strace says the offending process does all the time: ioctl(15, USBDEVFS_CLAIMINTERFACE, 0x7fffad353bfc) = -1 EBUSY (Device or resource busy) This repeasts endlessly. Please tell me how I can provide further information. Cheers, Fabian -- System Information: Debian Release: stretch/sid APT prefers testing APT policy: (990, 'testing'), (500, 'experimental'), (500, 'unstable') Architecture: amd64 (x86_64) Foreign Architectures: i386 Kernel: Linux 4.0.0-2-amd64 (SMP w/4 CPU cores) Locale: LANG=de_DE.utf8, LC_CTYPE=de_DE.utf8 (charmap=UTF-8) Shell: /bin/sh linked to /bin/dash Init: systemd (via /run/systemd/system) Versions of packages cups depends on: ii cups-client2.0.3-6 ii cups-common2.0.3-6 ii cups-core-drivers 2.0.3-6 ii cups-daemon2.0.3-6 ii cups-filters 1.0.69-1 ii cups-ppdc 1.7.5-12 ii cups-server-common 2.0.3-6 ii debconf [debconf-2.0] 1.5.56 ii ghostscript9.06~dfsg-2 ii libavahi-client3 0.6.31-5 ii libavahi-common3 0.6.31-5 ii libc-bin 2.19-18 ii libc6 2.19-18 ii libcups2 2.0.3-6 ii libcupscgi12.0.3-6 ii libcupsimage2 2.0.3-6 ii libcupsmime1 2.0.3-6 ii libcupsppdc1 2.0.3-6 ii libgcc11:5.1.1-12 ii libstdc++6 5.1.1-12 ii libusb-1.0-0 2:1.0.19-1 ii lsb-base 4.1+Debian13+nmu1 ii poppler-utils 0.26.5-2 ii procps 2:3.3.10-2 Versions of packages cups recommends: ii avahi-daemon 0.6.31-5 ii colord 1.2.1-1+b2 ii cups-filters [ghostscript-cups] 1.0.69-1 ii printer-driver-gutenprint5.2.10-3 Versions of packages cups suggests: pn cups-bsd pn cups-pdf ii foomatic-db-compressed-ppds [foomatic-db] 20150411-1 ii hplip 3.14.6-1+b2 ii printer-driver-hpcups 3.14.6-1+b2 ii smbclient 2:4.1.17+dfsg-4 ii udev 221-1 -- debconf information: cupsys/raw-print: true cupsys/backend: lpd, socket, usb, snmp, dnssd -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org