CUPS: "Filter failed", prints withheld

English Hardware
1

I upgraded from 15.0 to 15.1 a week ago (changing repo URLs and zypper dup). After that printing was OK

Yesterday I did a zypper up. I do not see any package there (from the History list in YaST > Software Managnment) connected to printing, but it is a rather long list and I do not claim to understand where all packeges are for.

Today prints are accepted by CUPS and stopped immediatly (they are in the queue and can be restarted). The printer makes no movement/noise whatsoever.
The general error shown is “Filter failed”.

I tried prints from Ocular (PDFs), Firefox (HTML pages), YaST printer configuration test print, and from a simple lp command.
Because the last one is the most simple and creates the smallest log:

E [02/Oct/2019:12:35:12 +0200] [Job 115] Job stopped due to filter errors; please consult the error_log file for details.
D [02/Oct/2019:12:35:12 +0200] [Job 115] The following messages were recorded from 12:35:12 to 12:35:12
D [02/Oct/2019:12:35:12 +0200] [Job 115] Applying default options...
D [02/Oct/2019:12:35:12 +0200] [Job 115] Adding start banner page "none".
D [02/Oct/2019:12:35:12 +0200] [Job 115] Queued on "hpdeskjetf4100series" by "henk".
D [02/Oct/2019:12:35:12 +0200] [Job 115] Auto-typing file...
D [02/Oct/2019:12:35:12 +0200] [Job 115] Request file type is text/plain.
D [02/Oct/2019:12:35:12 +0200] [Job 115] File of type text/plain queued by "henk".
D [02/Oct/2019:12:35:12 +0200] [Job 115] Adding end banner page "none".
D [02/Oct/2019:12:35:12 +0200] [Job 115] time-at-processing=1570012512
D [02/Oct/2019:12:35:12 +0200] [Job 115] 3 filters for job:
D [02/Oct/2019:12:35:12 +0200] [Job 115] texttopdf (text/plain to application/pdf, cost 32)
D [02/Oct/2019:12:35:12 +0200] [Job 115] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [02/Oct/2019:12:35:12 +0200] [Job 115] foomatic-rip (application/vnd.cups-pdf to printer/hpdeskjetf4100series, cost 0)
D [02/Oct/2019:12:35:12 +0200] [Job 115] job-sheets=none,none
D [02/Oct/2019:12:35:12 +0200] [Job 115] argv[0]="hpdeskjetf4100series"
D [02/Oct/2019:12:35:12 +0200] [Job 115] argv[1]="115"
D [02/Oct/2019:12:35:12 +0200] [Job 115] argv[2]="henk"
D [02/Oct/2019:12:35:12 +0200] [Job 115] argv[3]="file"
D [02/Oct/2019:12:35:12 +0200] [Job 115] argv[4]="1"
D [02/Oct/2019:12:35:12 +0200] [Job 115] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:9c7746b6-13de-334c-416e-7ade2b03e118 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1570012512 time-at-processing=1570012512 document-name-supplied=file"
D [02/Oct/2019:12:35:12 +0200] [Job 115] argv[6]="/var/spool/cups/d00115-001"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[2]="CUPS_DOCROOT=/usr/share/cups/webcontent"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[7]="CUPS_STATEDIR=/run/cups"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[8]="HOME=/var/spool/cups/tmp"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[10]="SERVER_ADMIN=root@boven.henm.xs4all.nl"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[11]="SOFTWARE=CUPS/2.2.7"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[13]="USER=root"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[14]="CUPS_MAX_MESSAGE=2047"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[17]="IPP_PORT=631"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[18]="CHARSET=utf-8"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[19]="LANG=nl_NL.UTF-8"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[20]="PPD=/etc/cups/ppd/hpdeskjetf4100series.ppd"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[21]="RIP_MAX_CACHE=128m"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[22]="CONTENT_TYPE=text/plain"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[23]="DEVICE_URI=hp:/usb/Deskjet_F4100_series?serial=CN7592H1KH04TJ"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[24]="PRINTER_INFO=HP Deskjet f4100 Series hpijs, 3.17.9"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[25]="PRINTER_LOCATION="
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[26]="PRINTER=hpdeskjetf4100series"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[27]="PRINTER_STATE_REASONS=marker-supply-low-warning"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[28]="CUPS_FILETYPE=document"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [02/Oct/2019:12:35:12 +0200] [Job 115] envp[30]="AUTH_I****"
D [02/Oct/2019:12:35:12 +0200] [Job 115] Started filter /usr/lib/cups/filter/texttopdf (PID 14653)
D [02/Oct/2019:12:35:12 +0200] [Job 115] Started filter /usr/lib/cups/filter/pdftopdf (PID 14654)
D [02/Oct/2019:12:35:12 +0200] [Job 115] Started filter /usr/lib/cups/filter/foomatic-rip (PID 14655)
D [02/Oct/2019:12:35:12 +0200] [Job 115] Started backend /usr/lib/cups/backend/hp (PID 14656)
D [02/Oct/2019:12:35:12 +0200] [Job 115] Calling FindDeviceById(cups-hpdeskjetf4100series)
D [02/Oct/2019:12:35:12 +0200] [Job 115] Failed to send: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
D [02/Oct/2019:12:35:12 +0200] [Job 115] Failed to get find device cups-hpdeskjetf4100series
D [02/Oct/2019:12:35:12 +0200] [Job 115] \'CM Color Calibration\' Mode in SPOOLER-LESS: Off
D [02/Oct/2019:12:35:12 +0200] [Job 115] Getting input from file 
D [02/Oct/2019:12:35:12 +0200] [Job 115] foomatic-rip version 1.20.3 running...
D [02/Oct/2019:12:35:12 +0200] [Job 115] Parsing PPD file ...
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option ColorSpace
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option Resolution
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option PageSize
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option Model
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option PrintoutMode
D [02/Oct/2019:12:35:12 +0200] [Job 115] pdftopdf: Last filter determined by the PPD: foomatic-rip; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option Quality
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option ImageableArea
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option PaperDimension
D [02/Oct/2019:12:35:12 +0200] [Job 115] Added option Font
D [02/Oct/2019:12:35:12 +0200] [Job 115] Parameter Summary
D [02/Oct/2019:12:35:12 +0200] [Job 115] -----------------
D [02/Oct/2019:12:35:12 +0200] [Job 115] Spooler: cups
D [02/Oct/2019:12:35:12 +0200] [Job 115] Printer: hpdeskjetf4100series
D [02/Oct/2019:12:35:12 +0200] [Job 115] Shell: /bin/bash
D [02/Oct/2019:12:35:12 +0200] [Job 115] PPD file: /etc/cups/ppd/hpdeskjetf4100series.ppd
D [02/Oct/2019:12:35:12 +0200] [Job 115] ATTR file: 
D [02/Oct/2019:12:35:12 +0200] [Job 115] Printer model: HP Deskjet f4100 Series hpijs, 3.17.9
D [02/Oct/2019:12:35:12 +0200] [Job 115] Job title: file
D [02/Oct/2019:12:35:12 +0200] [Job 115] File(s) to be printed:
D [02/Oct/2019:12:35:12 +0200] [Job 115] <STDIN>
D [02/Oct/2019:12:35:12 +0200] [Job 115] Ghostscript extra search path (\'GS_LIB\'): /usr/share/cups/fonts
D [02/Oct/2019:12:35:12 +0200] [Job 115] Printing system options:
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'finishings=3\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option finishings=3.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'number-up=1\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option number-up=1.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'job-uuid=urn:uuid:9c7746b6-13de-334c-416e-7ade2b03e118\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option job-uuid=urn:uuid:9c7746b6-13de-334c-416e-7ade2b03e118.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'job-originating-host-name=localhost\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option job-originating-host-name=localhost.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'date-time-at-creation=\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option date-time-at-creation=.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'date-time-at-processing=\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option date-time-at-processing=.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'time-at-creation=1570012512\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option time-at-creation=1570012512.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'time-at-processing=1570012512\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option time-at-processing=1570012512.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Pondering option \'document-name-supplied=file\'
D [02/Oct/2019:12:35:12 +0200] [Job 115] Unknown option document-name-supplied=file.
D [02/Oct/2019:12:35:12 +0200] [Job 115] CM Color Calibration Mode in CUPS: Off
D [02/Oct/2019:12:35:12 +0200] [Job 115] Options from the PPD file:
D [02/Oct/2019:12:35:12 +0200] [Job 115] ================================================
D [02/Oct/2019:12:35:12 +0200] [Job 115] File: <STDIN>
D [02/Oct/2019:12:35:12 +0200] [Job 115] ================================================
D [02/Oct/2019:12:35:12 +0200] [Job 115] Page = 595x842; 10,36 to 585,833
D [02/Oct/2019:12:35:12 +0200] [Job 115] PID 14653 (/usr/lib/cups/filter/texttopdf) exited with no errors.
D [02/Oct/2019:12:35:12 +0200] [Job 115] PAGE: 1 1
D [02/Oct/2019:12:35:12 +0200] [Job 115] Filetype: PDF
D [02/Oct/2019:12:35:12 +0200] [Job 115] Storing temporary files in /var/spool/cups/tmp
D [02/Oct/2019:12:35:12 +0200] [Job 115] PID 14654 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [02/Oct/2019:12:35:12 +0200] [Job 115] GPL Ghostscript 9.27: Unrecoverable error, exit code 1
D [02/Oct/2019:12:35:12 +0200] [Job 115] Process is dying with \"Unable to determine number of pages, page count: -1
D [02/Oct/2019:12:35:12 +0200] [Job 115] \", exit stat 3
D [02/Oct/2019:12:35:12 +0200] [Job 115] Cleaning up...
D [02/Oct/2019:12:35:12 +0200] [Job 115] prnt/backend/hp.c 919: ERROR: null print job total=0
D [02/Oct/2019:12:35:12 +0200] [Job 115] PID 14655 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3.
D [02/Oct/2019:12:35:12 +0200] [Job 115] Hint: Try setting the LogLevel to "debug" to find out more.
D [02/Oct/2019:12:35:12 +0200] [Job 115] PID 14656 (/usr/lib/cups/backend/hp) exited with no errors.
D [02/Oct/2019:12:35:12 +0200] [Job 115] End of messages
D [02/Oct/2019:12:35:12 +0200] [Job 115] printer-state=3(idle)
D [02/Oct/2019:12:35:12 +0200] [Job 115] printer-state-message="Filter failed"
D [02/Oct/2019:12:35:12 +0200] [Job 115] printer-state-reasons=marker-supply-low-warning

Of course I tried to interprete the last line: marker supply low warning.

Which supply?
There is paper enough.
No red lights blinking that show ink catridges being empty.

Nevertheless I changes cartridges. The printer prints it’s automatic check file (thus the printer on itself seems to be OK).

I am out of ideas. Anybody an idea about what “filter” is the talking?

2

Additional information:

Printer: HP Deskjet F4180
Connection: USB
Printer program: HP Deskjet f4100 Series hpijs, 3.17.9

3

Hi
I think it’s this bit that is the real issue;


D [02/Oct/2019:12:35:12 +0200] [Job 115] GPL Ghostscript 9.27: Unrecoverable error, exit code 1
D [02/Oct/2019:12:35:12 +0200] [Job 115] Process is dying with \"Unable to determine number of pages, page count: -1
D [02/Oct/2019:12:35:12 +0200] [Job 115] \", exit stat 3
D [02/Oct/2019:12:35:12 +0200] [Job 115] Cleaning up...

Did Ghostscript update?

4

Yes, ghostscript 9.27 is in that list.

Andlooking at the versions tab in YaST it most probably updated from 9.26a-lp151.3.3.1-x86_64 to 9.27-lp151.3.6.1-x86_64.

5

I downgraded ghostscript and ghostscript-x11 to those earlier version and it prints!

So, now I can of course block those two from further updates

But do you think a bug report is needed?

6

Hi
If you rollback to the 9.26a version, does it help?

7

“Filter” (in the CUPS world) is rather a generic term that applies to processing that takes place between the source document format and whatever language the printer uses.

8

Hi
And the open bug report…

https://bugzilla.opensuse.org/show_bug.cgi?id=1152720

9

Thanks all! (far within an hour)!

I added to the bug report.

10

Hi
So tested here with 15.1 and printing to a network printer (HP LaserJet P1102w) has no issues.

11

I mentioned in the bug that I have an USB connection.

I also added the lines you selected from the log.

Strange though, I would say that Ghostscript is not aware of the type of connection used.

12

Just tested here also, fully updated 15.1, GhostScript 9.27-lp151.3.6.1, printing to a Samsung M2825ND network printer from Firefox, Okular, and LibreOffice, all print OK.

Perhaps GhostScript is not part of the filter “chain” in the case of @malcolmlewis and myself.

13

Thanks also for testing.

I assume you can see if Ghostscript was used in

/var/log/cups/error_log
14

Only if there’s an error …

All I have in that log is repeated warning entries

W [02/Oct/2019:13:47:23 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
15

As you have seen above, I also have some of those kind. No idea why or what. But as long as it prints ;).

16

For colour managed printers I guess, this one is mono.

Out of curiosity I changed cups error level to “info” and now see there are three “filters” involved:

I [02/Oct/2019:15:36:49 +0100] [Job 34] Started filter /usr/lib/cups/filter/pdftopdf (PID 1717)
I [02/Oct/2019:15:36:49 +0100] [Job 34] Started filter /usr/lib/cups/filter/gstoraster (PID 1718)
I [02/Oct/2019:15:36:49 +0100] [Job 34] Started filter /usr/lib/cups/filter/rastertospl (PID 1719)

The first seems rather redundant, at least by name pdf to pdf

Second ,“gstoraster” is, according to: Filters and backends for CUPS - Browse /filter-gstoraster at SourceForge.net “a CUPS filter that converts PostScript or PDF to CUPS raster or PwgRaster format”

Lastly, “rastertospl” is raster to samsung printer language.

So no, it doesn’t look as if GhostScript is involved…

17

For those that were not sunscribed to get mails from the bug report:
https://bugzilla.suse.com/show_bug.cgi?id=1152720#c36
shows that for openSUSE 15.0 and 15.1 the patches are available.

Looking at YaST Online Update, I see the patches for cups-filters in the list.

Thus to be done:

  • unlock ghostscript and ghostscript-x11 (when you locked to the 26 versions)
  • apply the pacthes (YaST > Online Update, or zypper patch, or zyper up), which wll install ghostscript-27 and ghostscript-x11-27 and cups-filters-1.20.3