Monthly Archives: October 2016

CUPS Remote Printing Filter Failed

Posted on by
Reply

I keep getting bitten by this issue every time I set up a new printer on a new machine to print to a remote CUPS server that has the physical printer connected to it (via USB, for example), and every time I run into the same problem it takes me a little while until I remember what the probblem is. So, I have decided to document the problem (and the solution) for next time I run in the problem.

The printer is correctly configured on the server, and by “correctly configured” I mean that the printer is using the correct driver, and that printing is working, both locally on the machine with the attached printer, and remotely on other clients.

On the client side, the URI for the printer is correct; for example ipp://servername.example.com:631/printers/printer_name. Everything seems fine until a document is sent to the printer on the client — when this happens, the server’s cupsd (not the client’s), generates runs into a problem and nothing gets printed. The server’s cupsd error file (typically /var/log/cups/error_log) contains something like this:

D [16/Oct/2016:21:25:45 -0400] [Job 2] Queued on "HP_Officejet_2620_series" by "username".
 D [16/Oct/2016:21:25:45 -0400] [Job 2] File of type application/vnd.cups-raster queued by "username".
 D [16/Oct/2016:21:25:45 -0400] [Job 2] Adding end banner page "none".
 D [16/Oct/2016:21:25:45 -0400] [Job 2] time-at-processing=1476667545
 D [16/Oct/2016:21:25:45 -0400] [Job 2] 1 filters for job:
 D [16/Oct/2016:21:25:45 -0400] [Job 2] hpcups (application/vnd.cups-raster to printer/HP_Officejet_2620_series, cost 0)
 D [16/Oct/2016:21:25:45 -0400] [Job 2] job-sheets=none,none
 D [16/Oct/2016:21:25:45 -0400] [Job 2] argv[0]="HP_Officejet_2620_series"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] argv[1]="2"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] argv[2]="username"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] argv[3]="Untitled Document 1"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] argv[4]="1"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] argv[5]="job-uuid=urn:uuid:09c01fb4-c9b4-39de-6e4c-3d33a0710d25 job-originating-host-name=[v1.2002:4170:e35:1:81ae:ffff:ffff:83a7] date-time-at-creation= date-time-at-processing= time-at-creation=1476667545 time-at-processing=1476667545"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] argv[6]="/var/spool/cups/d00002-001"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[1]="CUPS_DATADIR=/usr/share/cups"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[6]="CUPS_SERVERROOT=/eD [16/Oct/2016:21:25:45 -0400] [Job 2] envp[26]="PRINTER=HP_Officejet_2620_series"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[27]="PRINTER_STATE_REASONS=none"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[28]="CUPS_FILETYPE=document"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[29]="FINAL_CONTENT_TYPE=printer/HP_Officejet_2620_series"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[30]="AUTH_I****"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] Started filter /usr/lib/cups/filter/hpcups (PID 5259)
 D [16/Oct/2016:21:25:45 -0400] [Job 2] Started backend /usr/lib/cups/backend/hp (PID 5260)
 D [16/Oct/2016:21:25:45 -0400] [Job 2] PID 5259 (/usr/lib/cups/filter/hpcups) stopped with status 1.
 D [16/Oct/2016:21:25:45 -0400] [Job 2] Hint: Try setting the LogLevel to "debug" to find out more.
 D [16/Oct/2016:21:25:45 -0400] [Job 2] PID 5260 (/usr/lib/cups/backend/hp) exited with no errors.
 D [16/Oct/2016:21:25:45 -0400] [Job 2] prnt/hpcups/HPCupsFilter.cpp 565: cupsRasterOpen failed, fd = 6
 D [16/Oct/2016:21:25:45 -0400] [Job 2] prnt/backend/hp.c 919: ERROR: null print job total=0
 D [16/Oct/2016:21:25:45 -0400] [Job 2] End of messages
 D [16/Oct/2016:21:25:45 -0400] [Job 2] printer-state=3(idle)
 D [16/Oct/2016:21:25:45 -0400] [Job 2] printer-state-message="Filter failed"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] printer-state-reasons=none
 tc/cups"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[7]="CUPS_STATEDIR=/run/cups"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[8]="HOME=/var/spool/cups/tmp"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[10]="SERVER_ADMIN=root@server.example.com"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[11]="SOFTWARE=CUPS/2.2.1"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[12]="TMPDIR=/var/spool/cups/tmp"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[13]="USER=root"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[14]="CUPS_MAX_MESSAGE=2047"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[16]="CUPS_ENCRYPTION=IfRequested"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[17]="IPP_PORT=631"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[18]="CHARSET=utf-8"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[19]="LANG=en_US.UTF-8"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[20]="PPD=/etc/cups/ppd/HP_Officejet_2620_series.ppd"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[21]="RIP_MAX_CACHE=128m"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[22]="CONTENT_TYPE=application/vnd.cups-raster"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[23]="DEVICE_URI=hp:/usb/Officejet_2620_series?serial=CN4654G2BG0600"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[24]="PRINTER_INFO=HP Officejet 2620 series"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[25]="PRINTER_LOCATION=My desk"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[26]="PRINTER=HP_Officejet_2620_series"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[27]="PRINTER_STATE_REASONS=none"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[28]="CUPS_FILETYPE=document"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[29]="FINAL_CONTENT_TYPE=printer/HP_Officejet_2620_series"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] envp[30]="AUTH_I****"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] Started filter /usr/lib/cups/filter/hpcups (PID 5259)
 D [16/Oct/2016:21:25:45 -0400] [Job 2] Started backend /usr/lib/cups/backend/hp (PID 5260)
 D [16/Oct/2016:21:25:45 -0400] [Job 2] PID 5259 (/usr/lib/cups/filter/hpcups) stopped with status 1.
 D [16/Oct/2016:21:25:45 -0400] [Job 2] Hint: Try setting the LogLevel to "debug" to find out more.
 D [16/Oct/2016:21:25:45 -0400] [Job 2] PID 5260 (/usr/lib/cups/backend/hp) exited with no errors.
 D [16/Oct/2016:21:25:45 -0400] [Job 2] prnt/hpcups/HPCupsFilter.cpp 565: cupsRasterOpen failed, fd = 6
 D [16/Oct/2016:21:25:45 -0400] [Job 2] prnt/backend/hp.c 919: ERROR: null print job total=0
 D [16/Oct/2016:21:25:45 -0400] [Job 2] End of messages
 D [16/Oct/2016:21:25:45 -0400] [Job 2] printer-state=3(idle)
 D [16/Oct/2016:21:25:45 -0400] [Job 2] printer-state-message="Filter failed"
 D [16/Oct/2016:21:25:45 -0400] [Job 2] printer-state-reasons=none

The problem is that “Filter failed”, and my understanding of the root cause of the problem is that the printer is configured on the client with the correct make and model for the printer that is physically connected to the server. So, if the printer is, for example, an Hewlett-Packard printer, the client will render the print job and send to the server the rendered job. The server is expecting the job in some other format (Postscript? PDF? It’s not important) and when it receives it in rendered format, for the exact printer make and model, then the filter on the server fails to render the print job.

The solution is to configure the printer on the client as a “raw” printer, i.e. a printer where the printer driver is not specified. This way the client sends the job “unrendered” and lets the server do the rendering according to the correct printer driver that is installed (on the server).

I remember that when I first ran into this problem it was not easy to figure out what was wrong. I enabled all the debugging knobs that I could find and nothing helped. It probably was some post to some random blog or Internet forum what gave me a clue, but it was not easy to find.

And to add insult to injury, using the Printer control panel on Ubuntu to modify the default settings of a printer (on a CUPS client), would change the local printer configuration from “raw” to a specific make and model, which would then trigger the problem explained above. This made me scratch my head and waste hours trying to get a previously working printer that stopped working to working state again.

Ggggrrrrr.

References

This RedHat bug report has good information on the issue and how clients and servers should be configured:

https://bugzilla cialis 5mg preis.redhat.com/show_bug.cgi?id=1010580

This ArchLinux forum discussion is very relevant to the problem:

https://bbs.archlinux.org/viewtopic.php?pid=1589908#p1589908

Finally, this ArchLinux wiki page:

https://wiki.archlinux.org/index.php/CUPS#Network_2

contains the following note, which describes precisely what the issue is:

“Warning: Avoid configuring both the server and the client with a printer filter – either the print queue on the client or the server should be ‘raw’. This avoids sending a print job through the filters for a printer twice, which can cause problems (for instance, [3]). See #Usage for an example of setting a print queue to ‘raw’.”