hpcups ppd fails to print; hpijs ppd works (hplip printer)

[Daniel D.]

The hplip in xenial is not compatible with the versions of cups and dbus (and various other libraries) in xenial.

The initial symptoms were that after running hp-setup -i (text mode only box), and attempting to print a test page from hplip, there was no output. After cancelling that job from http://<host>:631/... and attempting to print another test page from the CUPS interface, CUPS reporter 'filter failed'.

Reviewing error_log revealed the message 'unable to open inital device. quitting'.

While this *sounds* like a device error, hp-levels and hp-clean both work, so clearly the issue is not with access to the usb device (and the appropriate /dev/bus/usb/*/* device has group lp and group rw permissions).

Also some web searching reveals that this can be caused by e.g. ghostscript errors and is not necessarily indicative of an hardware device access issue.

Running hp-doctor gives the attached result

hplip version 3.16.3+repack0-1
cups 2.1.3-4
dbus 1.10.6-1ubuntu3

On an up-to-date as of 2016-04-18 01:00:00 -0400 Xenial system installed from final beta alternate CD.

[Daniel D. (cshoredaniel-deactivatedaccount)]

Didn't get assigned to right package

[Daniel D. (cshoredaniel-deactivatedaccount)]

For the record, the hp-doctor output *may* be a red herring. It turns
out there was a typo in a directive in my cupsd.conf (from a bad edit).

It is possible (although not certain) that the hp-doctor/hp-check
reports of incompatible/missing version is not showing the root cause,
but is an issue with hp-doctor/hp-check that needs to be addressed to
avoid user confusion.

However, it may actually be a version problem as I discovered the typo
after reinstalling with 14.04.4 and getting a different error from
hp-setup and seeing the directive error in /var/log/cups/error_log
(which was probably also in the xenial logs, but masked by the fact that
hp-setup appeared to work and that other errors appeared later (closer
to the faulty result).

On Trusty cups refused to even start, leading to finding the issue, on
Xenial things appeared to succeed until actual printing failed.

Regards,

Daniel

On 2016-04-18 02:58 AM, Daniel Curran-Dickinson wrote:
> Didn't get assigned to right package
>
> ** Package changed: libvirt (Ubuntu) => hplip (Ubuntu)
>

[Daniel D. (cshoredaniel-deactivatedaccount)]

It appears that in both xenial and trusty the hpcups ppds do not work
for some models (e.g. officejet j4500 series which uses deskjet 6500c as
cups model type).

On trusty hpijs ppd does work, but the hpcups ppd fails. Based on
comparing the ppds, it appears that there is a difference in what the
manufacturer/model name passed in the gs command line looks like.

This is consistent with the web search results mentioning ghostscript as
the one complaining about the device (i.e. at debug level the cups logs
show ghostscript failing to open bbox, but that's probably the wrong
device due to an error in command line that ends up getting used).

I will attempt to reproduce on a system from which I can pull the logs.

[Daniel D. (cshoredaniel-deactivatedaccount)]

A log from non-working hpcups ppd on trusty

D [18/Apr/2016:11:19:09 -0400] Discarding unused printer-state-changed
event...
D [18/Apr/2016:11:19:09 -0400] [Job 18] 4 filters for job:
D [18/Apr/2016:11:19:09 -0400] [Job 18] bannertopdf
(application/vnd.cups-pdf-banner to application/pdf, cost 32)
D [18/Apr/2016:11:19:09 -0400] [Job 18] pdftopdf (application/pdf to
application/vnd.cups-pdf, cost 66)
D [18/Apr/2016:11:19:09 -0400] [Job 18] gstoraster
(application/vnd.cups-pdf to application/vnd.cups-raster, cost 99)
D [18/Apr/2016:11:19:09 -0400] [Job 18] hpcups
(application/vnd.cups-raster to printer/HP_Officejet_J4500_series, cost 0)
D [18/Apr/2016:11:19:09 -0400] [Job 18] job-sheets=none,none
D [18/Apr/2016:11:19:09 -0400] [Job 18] argv[0]="HP_Officejet_J4500_series"
D [18/Apr/2016:11:19:09 -0400] [Job 18] argv[1]="18"
D [18/Apr/2016:11:19:09 -0400] [Job 18] argv[2]="daniel"
D [18/Apr/2016:11:19:09 -0400] [Job 18] argv[3]="Test Page"
D [18/Apr/2016:11:19:09 -0400] [Job 18] argv[4]="1"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
argv[5]="job-uuid=urn:uuid:dd45ed10-1f36-30de-71f1-733dbbf447e4
job-originating-host-name=localhost time-at-creation=1460992749
time-at-processing=1460992749"
D [18/Apr/2016:11:19:09 -0400] [Job 18] argv[6]="/var/spool/cups/d00018-001"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[1]="CUPS_DATADIR=/usr/share/cups"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[7]="CUPS_STATEDIR=/var/run/cups"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[8]="HOME=/var/spool/cups/tmp"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[10]="SERVER_ADMIN=root@printscan"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[11]="SOFTWARE=CUPS/1.7.2"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[12]="TMPDIR=/var/spool/cups/tmp"
[snip]
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[18]="IPP_PORT=631"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[19]="CHARSET=utf-8"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[20]="LANG=en_US.UTF-8"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[21]="PPD=/etc/cups/ppd/HP_Officejet_J4500_series.ppd"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[22]="RIP_MAX_CACHE=512k"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[23]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[24]="DEVICE_URI=hp:/usb/Officejet_J4500_series?serial=CN9CHD31FB052T"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[25]="PRINTER_INFO=HP
Officejet J4500 series"
D [18/Apr/2016:11:19:09 -0400] [Job 18] envp[26]="PRINTER_LOCATION="
D [18/Apr/2016:11:19:09 -0400] [Job 18]
envp[27]="PRINTER=HP_Officejet_J4500_series"
D [18/Apr/2016:11:19:09 -0400] [Jo...

[Daniel D. (cshoredaniel-deactivatedaccount)]

And a log from working hpijs on trusty

D [18/Apr/2016:11:46:46 -0400] [Job 21] envp[19]="CHARSET=utf-8"
D [18/Apr/2016:11:46:46 -0400] [Job 21] envp[20]="LANG=en_US.UTF-8"
D [18/Apr/2016:11:46:46 -0400] [Job 21]
envp[21]="PPD=/etc/cups/ppd/HP_Officejet_J4500_series.ppd"
D [18/Apr/2016:11:46:46 -0400] [Job 21] envp[22]="RIP_MAX_CACHE=512k"
D [18/Apr/2016:11:46:46 -0400] [Job 21]
envp[23]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
D [18/Apr/2016:11:46:46 -0400] [Job 21]
envp[24]="DEVICE_URI=hp:/usb/Officejet_J4500_series?serial=CN9CHD31FB052T"
D [18/Apr/2016:11:46:46 -0400] [Job 21] envp[25]="PRINTER_INFO=HP
Officejet J4500 series"
D [18/Apr/2016:11:46:46 -0400] [Job 21] envp[26]="PRINTER_LOCATION="
D [18/Apr/2016:11:46:46 -0400] [Job 21]
envp[27]="PRINTER=HP_Officejet_J4500_series"
D [18/Apr/2016:11:46:46 -0400] [Job 21]
envp[28]="PRINTER_STATE_REASONS=marker-supply-low-warning"
D [18/Apr/2016:11:46:46 -0400] [Job 21] envp[29]="CUPS_FILETYPE=document"
D [18/Apr/2016:11:46:46 -0400] [Job 21]
envp[30]="FINAL_CONTENT_TYPE=printer/HP_Officejet_J4500_series"
D [18/Apr/2016:11:46:46 -0400] [Job 21] envp[31]="AUTH_I****"
I [18/Apr/2016:11:46:46 -0400] [Job 21] Started filter
/usr/lib/cups/filter/bannertopdf (PID 7597)
I [18/Apr/2016:11:46:46 -0400] [Job 21] Started filter
/usr/lib/cups/filter/pdftopdf (PID 7598)
I [18/Apr/2016:11:46:46 -0400] [Job 21] Started filter
/usr/lib/cups/filter/foomatic-rip (PID 7599)
I [18/Apr/2016:11:46:46 -0400] [Job 21] Started backend
/usr/lib/cups/backend/hp (PID 7600)
D [18/Apr/2016:11:46:46 -0400] Discarding unused job-state-changed event...
D [18/Apr/2016:11:46:46 -0400] [Client 17] Returning IPP successful-ok
for Print-Job (ipp://localhost:631/printers/HP_Officejet_J4500_series)
from localhost
D [18/Apr/2016:11:46:46 -0400] [Client 17] Content-Length: 174
D [18/Apr/2016:11:46:46 -0400] cupsd is not idle any more, canceling
shutdown.
D [18/Apr/2016:11:46:46 -0400] [Client 17] cupsdWriteClient error=0,
used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH,
data_remaining=174, response=0x55b2473818d0(IPP_IDLE), pipe_pid=0, file=-1
D [18/Apr/2016:11:46:46 -0400] [Client 17] Writing IPP response,
ipp_state=DATA, old wused=0, new wused=0
D [18/Apr/2016:11:46:46 -0400] [Client 17] bytes=0, http_state=0,
data_remaining=0
D [18/Apr/2016:11:46:46 -0400] [Client 17] Waiting for request.
D [18/Apr/2016:11:46:46 -0400] cupsdSetBusyState: newbusy="Active
clients, printing jobs, and dirty files", busy="Active clients and dirty
files"
D [18/Apr/2016:11:46:46 -0400] cupsd is not idle any more, canceling
shutdown.
[snip]
D [18/Apr/2016:11:46:46 -0400] cupsdSetBusyState: newbusy="Printing jobs
and dirty files", busy="Active clients, printing jobs, and dirty files"
D [18/Apr/2016:11:46:46 -0400] cupsd is not idle any more, canceling
shutdown.
D [18/Apr/2016:11:46:46 -0400] [Job 21] Getting input from file
D [18/Apr/2016:11:46:46 -0400] cupsd is not idle any more, canceling
shutdown.
D [18/Apr/2016:11:46:46 -0400] [Job 21] foomatic-rip version 1.0.52
running...
D [18/Apr/2016:11:46:46 -0400] cupsd is not idle any more, canceling
shutdown.
D [18/Apr/2016:11:46:46 -0400] [Job 21] Parsing PPD file ...
D [18/Apr/2016:...

[gf (gf-interlinks-deactivatedaccount)]

Hello Daniel,
Thank you for submitting this bug and reporting a problem with cups. You made this bug report some time ago and Ubuntu has been updated since then.

Could you confirm that this is no longer a problem and that we can close the ticket?
If it is still a problem, are you still interested in finding a solution to this bug?
If you are, could you let us know, and in the current version, run the following (only once):
apport-collect BUGNUMBER
and upload the updated logs and and any other logs that are relevant for this particular issue.

Thank you again for helping make Ubuntu better.
G
[Ubuntu Bug Squad volunteer triager]

[Launchpad Janitor (janitor)]

[Expired for cups (Ubuntu) because there has been no activity for 60 days.]

[Launchpad Janitor (janitor)]

[Expired for hplip (Ubuntu) because there has been no activity for 60 days.]