Hello! When trying to set up the HP LaserJet 1300 printer under Linux (using USB connection), I have found that in some circumstances the printer locks up. In my configuration (Linux 2.4.21, CUPS 1.1.18) the first print job prints normally, but on the second print job the printer locks up before printing anything and needs to be powercycled; after this it prints the job normally, but locks up in the same way at the beginning of the next job...
I have tried to investigate the problem and found that the lockup happens when a program uses the LPIOC_GET_DEVICE_ID ioctl to get the IEEE-1284 device ID immediately after opening /dev/usb/lp0, and there is some data in the printer reverse channel at this time. The USB backend in CUPS unconditionally gets the device ID when asked to list all available ports (which happens during CUPS startup), and also can get the device ID on every print job if the printer is specified in the CUPS configuration by its model name and serial number (this is the default when using the builtin web interface for configuration). I turned on debugging in printer.c and added some more debugging statements - logging of both entry and exit in usblp_control_msg(), usb_submit_urb(), usb_unlink_urb(), and logging in the URB completion handler. Here is the annotated log. I turn on the printer: hub.c: new USB device 00:10.1-2, assigned address 6 printer.c: usblp0 set protocol 2 printer.c: > usblp_control_msg: rq: 0x00 dir: 1 recip: 1 value: 0 len: 0x3ff printer.c: < usblp_control_msg: rq: 0x00 dir: 1 recip: 1 value: 0 len: 0x3ff result: 158 printer.c: usblp0 Device ID string [len=158]="MFG:Hewlett-Packard;CMD:PJL,MLC,BIDI-ECP,PCL,POSTSCRIPT,PCLXL;MDL:hp LaserJet 1300;CLS:PRINTER;DES:Hewlett-Packard LaserJet 1300;MEM:8MB;COMMENT:RES=1200x1;" printer.c: > usblp_control_msg: rq: 0x01 dir: 1 recip: 1 value: 0 len: 0x1 printer.c: < usblp_control_msg: rq: 0x01 dir: 1 recip: 1 value: 0 len: 0x1 result: 1 printer.c: usblp0: USB Bidirectional printer dev 6 if 0 alt 1 proto 2 vid 0x03F0 pid 0x1017 Now I send the command to the printer (cat echo.pjl >/dev/usb/lp0): printer.c: > submit urb @dbdc101c, pipe=0xc0408680 printer.c: < submit urb @dbdc101c, pipe=0xc0408680, status=-115 printer.c: > submit urb @dbdc1074, pipe=0xc0008600 printer.c: < submit urb @dbdc1074, pipe=0xc0008600, status=-115 printer.c: < completed urb @dbdc1074, pipe=0xc0008600, status=0, len=29 printer.c: > unlink urb @dbdc1074, pipe=0xc0008600 printer.c: < unlink urb @dbdc1074, pipe=0xc0008600, status=0 printer.c: > unlink urb @dbdc101c, pipe=0xc0408680 printer.c: < completed urb @dbdc101c, pipe=0xc0408680, status=-2, len=0 printer.c: < unlink urb @dbdc101c, pipe=0xc0408680, status=-2 Then I start my test program which just tries to get the device ID with LPIOC_GET_DEVICE_ID (./printer_check /dev/usb/lp0): printer.c: > submit urb @dbdc101c, pipe=0xc0408680 printer.c: < submit urb @dbdc101c, pipe=0xc0408680, status=-115 printer.c: > usblp_control_msg: rq: 0x00 dir: 1 recip: 1 value: 0 len: 0x3ff printer.c: < completed urb @dbdc101c, pipe=0xc0408680, status=0, len=17 At this point the printer is hung - all 3 indicators at the front panel are lit (according to the printer documentation this means internal error). After USBLP_WRITE_TIMEOUT expires, the device ID read fails: usb_control/bulk_msg: timeout printer.c: < usblp_control_msg: rq: 0x00 dir: 1 recip: 1 value: 0 len: 0x3ff result: -110 printer.c: usblp0: error = -110 reading IEEE-1284 Device ID string I have added dumping of the full device_id_string buffer here (and cleared it before the call): printer.c: 0000: 00 9e 4d 46 47 3a 48 65 77 6c 65 74 74 2d 50 61 printer.c: 0010: 63 6b 61 72 64 3b 43 4d 44 3a 50 4a 4c 2c 4d 4c printer.c: 0020: 43 2c 42 49 44 49 2d 45 43 50 2c 50 43 4c 2c 50 printer.c: 0030: 4f 53 54 53 43 52 49 50 54 2c 50 43 4c 58 4c 3b printer.c: 0040: 4d 44 4c 3a 68 70 20 4c 61 73 65 72 4a 65 74 20 printer.c: 0050: 31 33 30 30 3b 43 4c 53 3a 50 52 49 4e 54 45 52 printer.c: 0060: 3b 44 45 53 3a 48 65 77 6c 65 74 74 2d 50 61 63 printer.c: 0070: 6b 61 72 64 20 4c 61 73 65 72 4a 65 74 20 31 33 printer.c: 0080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 [lots of lines with zeros skipped] printer.c: 03f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 printer.c: > unlink urb @dbdc1074, pipe=0xc0008600 printer.c: < unlink urb @dbdc1074, pipe=0xc0008600, status=0 printer.c: > unlink urb @dbdc101c, pipe=0xc0408680 printer.c: < unlink urb @dbdc101c, pipe=0xc0408680, status=0 Seems that the lockup happens in the middle of the device ID transfer (128 bytes were transferred successfully, but the last packet did not arrive). The printer can be returned to the operational state only by switching it off and back on. The lockup can also be triggered from a userspace program using usbdevfs (without the printer module loaded). I have attached such a program (usb_printer_test.c); it is invoked as ./usb_printer_test /proc/bus/usb/XXX/YYY <mode> <mode> is either "r" or "w"; the program tries to perform a bulk read or write in paralled with the device ID read. My tests with this program give the following results: $ ./usb_printer_test /proc/bus/usb/002/007 r Setting configuration 1 Claiming interface 0 Selecting altsetting 1 Reading ID... Device ID: "MFG:Hewlett-Packard;CMD:PJL,MLC,BIDI-ECP,PCL,POSTSCRIPT,PCLXL;MDL:hp LaserJet 1300;CLS:PRINTER;DES:Hewlett-Packard LaserJet 1300;MEM:8MB;COMMENT:RES=1200x1;" Writing 29 bytes Reading ID... Device ID: "MFG:Hewlett-Packard;CMD:PJL,MLC,BIDI-ECP,PCL,POSTSCRIPT,PCLXL;MDL:hp LaserJet 1300;CLS:PRINTER;DES:Hewlett-Packard LaserJet 1300;MEM:8MB;COMMENT:RES=1200x1;" Submitting URB Reading ID... ./usb_printer_test: usbdev_control_msg(read ID): Connection timed out Reaping URB status=0, length=17 $ ./usb_printer_test /proc/bus/usb/002/011 w Setting configuration 1 Claiming interface 0 Selecting altsetting 1 Reading ID... Device ID: "MFG:Hewlett-Packard;CMD:PJL,MLC,BIDI-ECP,PCL,POSTSCRIPT,PCLXL;MDL:hp LaserJet 1300;CLS:PRINTER;DES:Hewlett-Packard LaserJet 1300;MEM:8MB;COMMENT:RES=1200x1;" Submitting URB Reading ID... ./usb_printer_test: usbdev_control_msg(read ID): Connection timed out Reaping URB status=0, length=29 The read test causes the lockup every time; the write test needs about 10-15 tries, but eventually locks up the printer too. In both cases the bulk transaction completes successfully, but the device ID read fails. USBLP_REQ_GET_STATUS did not have this problem in my tests - only USBLP_REQ_GET_ID caused lockups when used with parallel bulk I/O operations. The lockups are reproducible with both usb-uhci and uhci drivers. I don't know what really happens on the wire, but probably the bulk transaction happens in the middle of the control transfer, which greatly confuses the printer firmware. As a workaround for such printers, we may need to avoid reading the device ID at the time LPIOC_GET_DEVICE_ID is called - instead we need to get the device ID at the initialization time (this is already done) and just return the saved ID in response to the ioctl. It is possible to reread the ID after calling usblp_set_protocol() - at this time URBs are unlinked, so reading the ID should be safe. I have made a patch with this workaround - it is attached. The patch is against drivers/usb/printer.c in Linux 2.4.21/2.4.22-rc2. With this workaround the printer lockup with CUPS is avoided. -- Sergey Vlasov
linux-2.4.21-usb-printer-get-id-lockup.patch
Description: Binary data
echo.pjl
Description: Binary data
printer_check.c
Description: Binary data
usb_printer_test.c
Description: Binary data
pgp00000.pgp
Description: PGP signature
