Version: 1.1.19 CUPS.org User: mbrown.fensystems.co
This problem relates to printing via IPP.
Several HP LaserJet 2200n printers started printing multiple (up to several hundred) copies of pages after upgrading to CUPS 1.19. Printers are attached to the network and communicate via IPP.
strace and ethereal revealed that job was being sent and expected IPP reply was being received, but CUPS would print "INFO: Printer is busy; retrying print job..." and would resend the job.
Enabling debugging showed that ippReadIO was failing to read the IPP header. Relevant log portion is reproduced here:
cupsDoFileRequest: update... httpUpdate(0x8056610) httpGets(0xbfff39c0, 1024, 0x8056610) httpGets(): Returning "HTTP/1.1 200 OK" HTTP/1.1 200 OK httpGets(0xbfff39c0, 1024, 0x8056610) httpGets(): Returning "Server: Agranat-EmWeb/R5_2_6" Server: Agranat-EmWeb/R5_2_6 httpUpdate: unknown field Server seen! httpGets(0xbfff39c0, 1024, 0x8056610) httpGets(): Returning "Transfer-Encoding: chunked" Transfer-Encoding: chunked httpGets(0xbfff39c0, 1024, 0x8056610) httpGets(): Returning "Content-Type: application/ipp" Content-Type: application/ipp httpGets(0xbfff39c0, 1024, 0x8056610) httpGets(): Returning "Cache-Control: public,max-age=3600" Cache-Control: public,max-age=3600 httpUpdate: unknown field Cache-Control seen! httpGets(0xbfff39c0, 1024, 0x8056610) httpGets(): Returning ""
httpGetLength(0x8056610), state = 7 httpGetLength: chunked request! cupsDoFileRequest: status = 200 cupsDoFileRequest: response... ippNew(): 0x805b5e0 ippRead(http=0x8056610, ipp=0x805b5e0), data_remaining=0 http->state = 7 ippReadIO(0x8056610, 0x40021650, 1, (nil), 0x805b5e0) ipp_read_http(http=0x8056610, buffer=0xbffebd90, length=8) tbytes = 0, http->state = 7 returning -1 bytes... ippReadIO: Unable to read header (-1 bytes read)! IPP read error! ippDelete(): 0x805b5e0 httpRead(0x8056610, 0xbfff1dc0, 8192) httpRead: Getting chunk length... httpGets(0xbfff1d70, 32, 0x8056610) httpGets(): Returning "000000bb" httpRead: data_remaining = 187 httpRead: grabbing 187 bytes from input buffer... httpGets(0xbfff1d70, 32, 0x8056610) httpGets(): Returning ""
Further analysis showed that CUPS is timing out during its one-second wait for the printer to send the IPP header. This timeout was added in version 1.79 of cups/ipp.c. Backing out this change (i.e. removing the call to httpWait) fixes the problem. It seems that at least the HP2200n takes more than a second before sending the IPP header.
From looking at the code, it seems that this problem is still present in the latest CVS version of cups/ipp.c.
Michael
该提问来源于开源项目：apple/cups
