pdftops-renderer-default - unnecessary and misdirecting error messages - obsolete filters

[thx1111]

Arch Linux
cups 2.3.1-1
poppler 0.87.0-1
HP_LaserJet_6MP
device for PS_HP_LaserJet_6MP: hp:/par/HP_LaserJet_6MP?device=/dev/parport0

..."Print Test Page"
pdftops-renderer-default:
gs - takes a long time to print, as has been stated, but otherwise works
mupdf - prints many pages of random characters, two lines per page
pdftops - "Backend returned status -139 (crashed)"
pdftocairo - seems to work perfectly well, except, an error message is generated -

Grayscale/monochrome printing requested for this job but Poppler is not able to convert to grayscale/monochrome PostScript.
Use "pdftops-renderer" option (see README file) to use Ghostscript or MuPDF for the PDF -> PostScript conversion.

1. Where is this mythical README file?
2. There is no such explanation at https://github.com/apple/cups - READM.md
3. Obviously, the error message is both wrong and misleading.
4. The set of options recommended fails to include specifically the option which actually works.
5. We take note that the user-space pdftocairo is, in fact, also part of Poppler.
6. The user-space Poppler pdftops specifically offers:
   OPTIONS
   -level1
   ... This also converts all images to black and white. ...

So, with Poppler, both pdftocairo and pdftops are "able to convert to grayscale/monochrome PostScript", contrary to what is claimed in the error message.

It would seem that the version of /usr/lib/cups/filter/pdftops used is, perhaps, obsolete, and that the error message generated is both unnecessary and misdirecting.

[zdohnal]

1. Where is this mythical README file?

2. There is no such explanation at https://github.com/apple/cups - READM.md

The README mentioned in the log is cups-filters's README - it is a different project https://github.com/OpenPrinting/cups-filters .

Would you mind sharing your issue there? Plus mentioning a general README in filter's log can result in misleading users to think some filters are part of CUPS, not cups-filters, when they see it in CUPS logs.

[thx1111]

Thanks for pointing out that there is an "other project" issue. I really hadn't thought about it that way.

Hmm - a related aspect, not just that the README referenced in the error log is from a completely different project, but - I have come to realize - that the "backend" driver - here, the "hp" backend driver, in this case - is also from a completely different project, HPLIP.

As a consequence of the hp backend, it seems that the error message "Backend returned status -139 (crashed)" would be generated by that hp backend, and not at all anything to do with CUPS itself. And then, that error message, "...crashed", is also unnecessary and misdirecting. In this case, it appears that the hp backend contains an arbitrary 80 second timer, timing between job submission and job completion, so that, when this old printer takes more than 80 seconds to process a page, using Postcript as the printer language, the hp backend 1) issues the false error message, 2) stop transmitting, 3) terminates the job, and 4) disables the printer - where the "stop printer" policy is the default. Even then, the printer still prints the first page of the print job just fine, and then stops, since the remaining pages are never sent.

Contrast this behavior with the operation of the normal CUPS parallel printer driver, in which case, the printer just prints the job. There are no false error messages, no lost print job, no disabled printer requiring manual intervention. Sure, the printing may seem a little "slow", but slow is nothing to do with CUPS.

So, what can be done to "force" these "other projects", which are providing both filters and backends, to "take responsibility" for the error messages they generate in the CUPS error log, and to disclose the otherwise "silent" policies they impose upon the user?

The problem here is that, while to the developers, this distinction between "CUPS proper", and these several "other projects" is probably self-evident, in contrast, with the typical computer user - and to the experienced computer administrator who has not spent a lot of time mucking-about with their printer - all of this behavior is "just CUPS, all CUPS". "Silent errors", unnecessary and misleading error messages, foolish policies - time-outs that are too short, silently "disabling" a printer on minor errors - are, in fact, disastrous. For the user, "I tried to print - nothing happened - I tried again - now the printer doesn't work."

It might be nice, for instance, to, at least, require other project error messages to identify their source, the project responsible for the message. And then, it might be more desirable that CUPS impose greater discipline upon "CUPS compatible" components, which overwhelmingly impact the end-user experience of CUPS itself.

It has actually taken me quite a bit of time, reading-up on CUPS, and its history, and its several compatible projects, and their histories, to even appreciate the problem space. And I am quite sure, based upon personal experience, that most users are not so willing to spend that much time on printing issues. Anything - and everything - that can be done, with user feedback, to provide verbose and specific error messages, to provide policy disclosure and "discoverability", to automatically disclose printer status, and to direct the user to where to look for help, would be very welcome and appreciated.

Parenthetically, also maybe less "noise" in the error log file. "Saving subscriptions.conf...", "Expiring subscriptions..." - not even "man 5 subscriptions.conf" or an internet search can explain what any of that means. And there's a lot of it. Providing an "error message" - how is saving or expiring a subscription a kind of "error"? - which is meaningless to the casual observer, and undiscoverable to basic investigation, is, at best, confusing.

[zdohnal]

Thanks for pointing out that there is an "other project" issue. I really hadn't thought about it that way.

No problem :) .

Hmm - a related aspect, not just that the README referenced in the error log is from a completely different project, but - I have come to realize - that the "backend" driver - here, the "hp" backend driver, in this case - is also from a completely different project, HPLIP.

Yes, you are right - hplip provides PPD support for HP devices right now. Though I would like to mention the new HP printers (released in 2010+) support IPP everywhere over network, so hplip is not needed for printing over network.
For USB printers, there is ipp-over-usb feature (it is supported by newer devices than IPP everywhere ones from my experience - about 2018+), for which you don't need HPLIP either, but you need https://github.com/OpenPrinting/ipp-usb .
If you need scanning functionality of newer HP devices, there are projects sane-airscan https://github.com/alexpevzner/sane-airscan or sane-escl in sane-backends for supporting it.

So in the right circumstances, you don't need HPLIP at all.

As a consequence of the hp backend, it seems that the error message "Backend returned status -139 (crashed)" would be generated by that hp backend, and not at all anything to do with CUPS itself. And then, that error message, "...crashed", is also unnecessary and misdirecting.

The message is connected to CUPS in a way - cupsd as the scheduler spawns needed backend and filters as new processes, so it needs to check its exit codes. The message is created by cupsd with exit code and string corresponding to exit code from hp backend.
There should be other error message from the backend, which should specify the real cause of crash, but that's in the competence of hplip...

Contrast this behavior with the operation of the normal CUPS parallel printer driver, in which case, the printer just prints the job. There are no false error messages, no lost print job, no disabled printer requiring manual intervention. Sure, the printing may seem a little "slow", but slow is nothing to do with CUPS.

IMO the previous message is false - cupsd just stated the backend failed, which is not the case of parallel backend, so there is no such 'false' error message...

So, what can be done to "force" these "other projects", which are providing both filters and backends, to "take responsibility" for the error messages they generate in the CUPS error log, and to disclose the otherwise "silent" policies they impose upon the user?

The right way is to open tickets on their bug trackers, mention the problem, ideally propose the solution in form of pull request/patch.

The problem here is that, while to the developers, this distinction between "CUPS proper", and these several "other projects" is probably self-evident, in contrast, with the typical computer user - and to the experienced computer administrator who has not spent a lot of time mucking-about with their printer - all of this behavior is "just CUPS, all CUPS". "Silent errors", unnecessary and misleading error messages, foolish policies - time-outs that are too short, silently "disabling" a printer on minor errors - are, in fact, disastrous. For the user, "I tried to print - nothing happened - I tried again - now the printer doesn't work."

There are several sources for users which mention these relationships between CUPS/cups-filters atd - f.e. https://wiki.archlinux.org/index.php/CUPS . Regarding the problems you mentioned, I would say some of them are programmer's errors, but IMO disabling the print queue by cupsd when the backend crashes (or it tells it crashes at least...), which is not a minor error, is not wrong.

It might be nice, for instance, to, at least, require other project error messages to identify their source, the project responsible for the message. And then, it might be more desirable that CUPS impose greater discipline upon "CUPS compatible" components, which overwhelmingly impact the end-user experience of CUPS itself.

IMO the project name is misleading in regular logs - filter's name or backend's name would be fine - when you search the name on the internet, it gives you a link to the project. Regarding imposing greater discipline upon CUPS compatible components it is in the competence CUPS compatible component's developer - cupsd just connects pipes of forked processes, redirecting their stdouts/stdins to other filter/backend in the chain and stderr to systemd-journald/file. Then the filters/backends uses standard C printing functions to produce debug/error messages which go directly to logging.
If cupsd would like to impose some logging discipline, IMO it would need to have public logging function, which would impose such discipline. But it would not work for several unmaintained/unresponsive printer drivers projects, because they will not move to new logging and logging would stop working for them...

Parenthetically, also maybe less "noise" in the error log file. "Saving subscriptions.conf...", "Expiring subscriptions..." - not even "man 5 subscriptions.conf" or an internet search can explain what any of that means. And there's a lot of it. Providing an "error message" - how is saving or expiring a subscription a kind of "error"? - which is meaningless to the casual observer, and undiscoverable to basic investigation, is, at best, confusing.

It seems you mistakes error messages and debug logging - those specific messages appear only in debug logging enabled.

[michaelrsweet]

This isn't an Apple CUPS issue; see the OpenPrinting cups-filters project.