You are not logged in.
Hi,
I'm trying to setup my old deskjet which has previously worked fine under Ubuntu.
hp-setup (with GUI) detects a deskjet 5100 but does not find a ppd file. Manually browsing for one yields hp-deskjet_5100.ppd.gz in /usr/share/ppd/HP,
but if I select it nothing happens. I tried running hp-setup -i -a and manually specifying the path to the file above but that results in:
Traceback (most recent call last):
File "/usr/bin/hp-setup", line 560, in <module>
desc = nickname_pat.search(nickname).group(1)
TypeError: cannot use a string pattern on a bytes-like objector alternatively:
error: File not found or not an appropriate (PPD) file.if I put double quotes around the file path.
I'm still looking for a solution but maybe someone here knows what I'm doing wrong.
EDIT:
Alright, although I could not solve my problems with hp-setup, I've now successfully added my printer in the CUPS browser-interface.
But under the "Printers" tab it's Status reads:
Idle - "Unable to send data to printer."Trying to print a test page changes the Status to:
Processing - "Sending data to printer."But the printer is not responding in any way.
As far as I know the color cartrige is most likely be dried up or empty (which I'm fairly certain would prevent normal usage),
would this explain why I cannot communicate with the printer? Shouldn't I receive some sort of error message?
I don't have access to another cartridge right now and I'd like to sort this out as fast as possible, any help would be appreciated.
Last edited by Time0o (2016-10-29 16:20:50)
Offline
How are you connecting to the printer - parallel/usb/ethernet?
Offline
I'm curious about your first issue - what version of hplip are you running? I can't reproduce here but, IIRC, that error generally suggests that the developer has assumed python 2, which is a bug and should be reported. This seems to be the same problem, albeit without any useful information...
You can use hp-levels to find the reported cartridge level. If you could post the full error log as detailed in the wiki, that would be helpful. Additionally, could you post the output of
# lpstat -tand
/etc/cups/printers.conf(you will need to be root for both)?
That could be caused by using the hpijs driver instead of the hplip driver (so use the hp-deskjet_5100.ppd.gz PPD instead of the hp-deskjet_5100-hpijs.ppd.gz PPD), or if you are not using a hp:/ URI.
Offline
I'm connected via USB and I have the hplip 3.16.9-1 package installed.
I've tried running:
python2 /usr/bin/hp-setupBut this results in:
Traceback (most recent call last):
File "/usr/bin/hp-setup", line 48, in <module>
from base import device, utils, tui, models, module, services, os_utils
File "/usr/share/hplip/base/device.py", line 42, in <module>
from . import status
File "/usr/share/hplip/base/status.py", line 33, in <module>
import cupsext
ImportError: No module named cupsexthp-levels does not find a "device that supports this feature"
cups error log is showing:
E [29/Oct/2016:17:34:43 +0200] [Client 27] Returning HTTP Forbidden for CUPS-Get-Devices (no URI) from localhost
E [29/Oct/2016:17:34:43 +0200] [CGI] CUPS-Get-Devices request failed with status 401: Forbidden
E [29/Oct/2016:17:34:50 +0200] [Client 32] Returning HTTP Forbidden for CUPS-Get-Devices (no URI) from localhost
E [29/Oct/2016:17:34:50 +0200] [CGI] CUPS-Get-Devices request failed with status 401: Forbidden
W [29/Oct/2016:17:42:38 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'hp_deskjet_5100-Gray..\' already exists
W [29/Oct/2016:17:42:38 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'hp_deskjet_5100-RGB..\' already exists
E [29/Oct/2016:17:59:48 +0200] [Job 2] Unable to send data to printer.
E [29/Oct/2016:18:26:17 +0200] [Job 5] Stopping unresponsive job.lpstat -t:
scheduler is running
no system default destination
device for hp_deskjet_5100: usb://hp/deskjet%205100?serial=HU36C1Y16NC3
hp_deskjet_5100 accepting requests since Sun 30 Oct 2016 12:05:24 PM CET
printer hp_deskjet_5100 now printing hp_deskjet_5100-6. enabled since Sun 30 Oct 2016 12:05:24 PM CET
Sending data to printer.
hp_deskjet_5100-6 anonymous 1024 Sun 30 Oct 2016 12:05:24 PM CET/etc/cups/printers.conf:
# Printer configuration file for CUPS v2.2.1
# Written by cupsd on 2016-10-29 17:57
# DO NOT EDIT THIS FILE WHEN CUPSD IS RUNNING
<Printer hp_deskjet_5100>
UUID urn:uuid:18741d59-89e3-35ad-7436-414a8fa6eeaa
Info hp deskjet 5100
Location
MakeModel HP Deskjet 5100 hpijs, 3.16.9
DeviceURI usb://hp/deskjet%205100?serial=HU36C1Y16NC3
State Idle
StateTime 1477756611
ConfigTime 1477756609
Type 8425500
Accepting Yes
Shared No
JobSheets none none
QuotaPeriod 0
PageLimit 0
KLimit 0
OpPolicy default
ErrorPolicy stop-printer
</Printer>Offline
You seem to be using the hpijs driver - use the hplip one instead. If that doesn't work, you will need to change the log level to debug, try to print something, and then repost the entire contents of the error log.
EDIT: I'm not sure how else to check the ink level - perhaps someone else has an idea?
Last edited by pypi (2016-10-30 21:23:29)
Offline
https://aur.archlinux.org/packages/hplip-plugin/
You might want to try https://aur.archlinux.org/packages/foo2zjs/ instead of hplip
Offline
https://aur.archlinux.org/packages/hplip-plugin/
You might want to try https://aur.archlinux.org/packages/foo2zjs/ instead of hplip
The OP shouldn't need hplip-plugin (see http://hplipopensource.com/hplip-web/mo … 5100.html).
I don't believe that the uses zjs (it's probably a PCL-based printer given how old it is) - it's also not on the list of printers supported by foo2zjs.
Offline
I'll add a complete error log:
D [31/Oct/2016:16:35:24 +0100] [Client 49] POST /printers/HP_deskjet_5100 HTTP/1.1
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [31/Oct/2016:16:35:24 +0100] [Client 49] Read: status=200
D [31/Oct/2016:16:35:24 +0100] [Client 49] Authorized as "timo" using Basic.
D [31/Oct/2016:16:35:24 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/run/cups"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@timo-t460"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/2.2.1"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[13] = "USER=root"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[15] = "CUPS_SERVER=/run/cups/cups.sock"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[19] = "LANG=en_US.UTF8"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[22] = "SERVER_NAME=127.0.0.1"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[26] = "SCRIPT_NAME=/printers/HP_deskjet_5100"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/printers/HP_deskjet_5100"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[28] = "PATH_INFO=/HP_deskjet_5100"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[29] = "REMOTE_USER=timo"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=88b1aa6a41e9639fd2af6338f41a1b2f"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:49.0) Gecko/20100101 Firefox/49.0"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[33] = "HTTP_REFERER=http://127.0.0.1:631/printers/HP_deskjet_5100"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[34] = "REQUEST_METHOD=POST"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[35] = "CONTENT_LENGTH=64"
D [31/Oct/2016:16:35:24 +0100] [CGI] envp[36] = "CONTENT_TYPE=application/x-www-form-urlencoded"
D [31/Oct/2016:16:35:24 +0100] cupsdAddCert: Adding certificate for PID 757
D [31/Oct/2016:16:35:24 +0100] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 757)
I [31/Oct/2016:16:35:24 +0100] [Client 49] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=757, file=17)
D [31/Oct/2016:16:35:24 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:24 +0100] [CGI] org.cups.sid cookie is \"88b1aa6a41e9639fd2af6338f41a1b2f\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: org.cups.sid=\"88b1aa6a41e9639fd2af6338f41a1b2f\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: OP=\"print-test-page\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:24 +0100] [Client 102] Server address is "/run/cups/cups.sock".
D [31/Oct/2016:16:35:24 +0100] [Client 102] Accepted from localhost (Domain)
D [31/Oct/2016:16:35:24 +0100] [Client 102] Waiting for request.
D [31/Oct/2016:16:35:24 +0100] [Client 102] POST /printers/HP_deskjet_5100 HTTP/1.1
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:24 +0100] [Client 102] Read: status=200
D [31/Oct/2016:16:35:24 +0100] [Client 102] No authentication data provided.
D [31/Oct/2016:16:35:24 +0100] [Client 102] 2.0 Print-Job 1
D [31/Oct/2016:16:35:24 +0100] Print-Job ipp://localhost:631/printers/HP_deskjet_5100
D [31/Oct/2016:16:35:24 +0100] [Job ???] Auto-typing file...
I [31/Oct/2016:16:35:24 +0100] [Job ???] Request file type is application/vnd.cups-pdf-banner.
D [31/Oct/2016:16:35:24 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:24 +0100] add_job: requesting-user-name="timo"
D [31/Oct/2016:16:35:24 +0100] Adding default job-sheets values "none,none"...
I [31/Oct/2016:16:35:24 +0100] [Job 13] Adding start banner page "none".
D [31/Oct/2016:16:35:24 +0100] Discarding unused job-created event...
D [31/Oct/2016:16:35:24 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [31/Oct/2016:16:35:24 +0100] [Job 13] Adding end banner page "none".
I [31/Oct/2016:16:35:24 +0100] [Job 13] File of type application/vnd.cups-pdf-banner queued by "timo".
D [31/Oct/2016:16:35:24 +0100] [Job 13] hold_until=0
I [31/Oct/2016:16:35:24 +0100] [Job 13] Queued on "HP_deskjet_5100" by "timo".
D [31/Oct/2016:16:35:24 +0100] [Job 13] time-at-processing=1477928124
D [31/Oct/2016:16:35:24 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:24 +0100] Discarding unused printer-state-changed event...
D [31/Oct/2016:16:35:24 +0100] [Job 13] 4 filters for job:
D [31/Oct/2016:16:35:24 +0100] [Job 13] bannertopdf (application/vnd.cups-pdf-banner to application/pdf, cost 32)
D [31/Oct/2016:16:35:24 +0100] [Job 13] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [31/Oct/2016:16:35:24 +0100] [Job 13] gstoraster (application/vnd.cups-pdf to application/vnd.cups-raster, cost 99)
D [31/Oct/2016:16:35:24 +0100] [Job 13] hpcups (application/vnd.cups-raster to printer/HP_deskjet_5100, cost 0)
D [31/Oct/2016:16:35:24 +0100] [Job 13] job-sheets=none,none
D [31/Oct/2016:16:35:24 +0100] [Job 13] argv[0]="HP_deskjet_5100"
D [31/Oct/2016:16:35:24 +0100] [Job 13] argv[1]="13"
D [31/Oct/2016:16:35:24 +0100] [Job 13] argv[2]="timo"
D [31/Oct/2016:16:35:24 +0100] [Job 13] argv[3]="Test Page"
D [31/Oct/2016:16:35:24 +0100] [Job 13] argv[4]="1"
D [31/Oct/2016:16:35:24 +0100] [Job 13] argv[5]="job-uuid=urn:uuid:16f6f67f-075b-30a3-5149-e930d105d4fb job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1477928124 time-at-processing=1477928124"
D [31/Oct/2016:16:35:24 +0100] [Job 13] argv[6]="/var/spool/cups/d00013-001"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[7]="CUPS_STATEDIR=/run/cups"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[8]="HOME=/var/spool/cups/tmp"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[10]="SERVER_ADMIN=root@timo-t460"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[11]="SOFTWARE=CUPS/2.2.1"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[13]="USER=root"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[14]="CUPS_MAX_MESSAGE=2047"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[17]="IPP_PORT=631"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[18]="CHARSET=utf-8"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[19]="LANG=en_US.UTF-8"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[20]="PPD=/etc/cups/ppd/HP_deskjet_5100.ppd"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[21]="RIP_MAX_CACHE=128m"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[22]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[23]="DEVICE_URI=hp:/usb/deskjet_5100?serial=HU36C1Y16NC3"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[24]="PRINTER_INFO=HP deskjet 5100"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[25]="PRINTER_LOCATION="
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[26]="PRINTER=HP_deskjet_5100"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[27]="PRINTER_STATE_REASONS=none"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[28]="CUPS_FILETYPE=document"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-raster"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[30]="AUTH_I****"
I [31/Oct/2016:16:35:24 +0100] [Job 13] Started filter /usr/lib/cups/filter/bannertopdf (PID 758)
I [31/Oct/2016:16:35:24 +0100] [Job 13] Started filter /usr/lib/cups/filter/pdftopdf (PID 759)
I [31/Oct/2016:16:35:24 +0100] [Job 13] Started filter /usr/lib/cups/filter/gstoraster (PID 760)
I [31/Oct/2016:16:35:24 +0100] [Job 13] Started filter /usr/lib/cups/filter/hpcups (PID 761)
I [31/Oct/2016:16:35:24 +0100] [Job 13] Started backend /usr/lib/cups/backend/hp (PID 762)
D [31/Oct/2016:16:35:24 +0100] Discarding unused job-state-changed event...
D [31/Oct/2016:16:35:24 +0100] [Client 102] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HP_deskjet_5100) from localhost
D [31/Oct/2016:16:35:24 +0100] [Client 102] Content-Length: 192
D [31/Oct/2016:16:35:24 +0100] [Client 102] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [31/Oct/2016:16:35:24 +0100] [Client 102] con->http=0x55e4b5a396f0
D [31/Oct/2016:16:35:24 +0100] [Client 102] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=192, response=0x55e4b5ae6c30(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [31/Oct/2016:16:35:24 +0100] [Client 102] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [31/Oct/2016:16:35:24 +0100] [Client 102] bytes=0, http_state=0, data_remaining=192
D [31/Oct/2016:16:35:24 +0100] [Client 102] Flushing write buffer.
D [31/Oct/2016:16:35:24 +0100] [Client 102] New state is HTTP_STATE_WAITING
D [31/Oct/2016:16:35:24 +0100] [Client 102] Waiting for request.
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"127.0.0.1\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"timo\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"127.0.0.1\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"timo\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetArray: job_uri[0]=\"/jobs/13\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetArray: job_id[0]=\"13\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetArray: job_state[0]=\"3\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetArray: job_state_message[0]=\"\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetArray: job_state_reasons[0]=\"none\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: refresh_page=\"2;URL=/printers/HP_deskjet_5100\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: TITLE=\"Print Test Page\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"127.0.0.1\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"timo\"
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [31/Oct/2016:16:35:24 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:24 +0100] [Client 102] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [31/Oct/2016:16:35:24 +0100] [Client 102] Closing connection.
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [31/Oct/2016:16:35:24 +0100] PID 757 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [31/Oct/2016:16:35:24 +0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] pdftopdf: Last filter determined by the PPD: hpcups; FINAL_CONTENT_TYPE: application/vnd.cups-raster => pdftopdf will not log pages in page_log.
D [31/Oct/2016:16:35:24 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:24 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=757, file=17
D [31/Oct/2016:16:35:24 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:24 +0100] [Client 49] Script header: Content-Type: text/html;charset=utf-8
D [31/Oct/2016:16:35:24 +0100] [Client 49] Script header:
D [31/Oct/2016:16:35:24 +0100] [Client 49] Sending status 200 for CGI.
D [31/Oct/2016:16:35:24 +0100] [Client 49] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [31/Oct/2016:16:35:24 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:24 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=757, file=17
D [31/Oct/2016:16:35:24 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:24 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:24 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:24 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=757, file=17
D [31/Oct/2016:16:35:24 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:24 +0100] [Client 49] Sending 0-length chunk.
D [31/Oct/2016:16:35:24 +0100] [Client 49] Flushing write buffer.
D [31/Oct/2016:16:35:24 +0100] [Client 49] New state is HTTP_STATE_WAITING
D [31/Oct/2016:16:35:24 +0100] [Client 49] Waiting for request.
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [31/Oct/2016:16:35:24 +0100] [Job 13] OUTFORMAT=\"(null)\", so output format will be CUPS/PWG Raster
D [31/Oct/2016:16:35:24 +0100] [Job 13] PDF template file doesn\'t have form. It\'s okay.
D [31/Oct/2016:16:35:24 +0100] [Job 13] PID 758 (/usr/lib/cups/filter/bannertopdf) exited with no errors.
D [31/Oct/2016:16:35:24 +0100] [Job 13] PID 759 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [31/Oct/2016:16:35:24 +0100] [Job 13] Color Manager: Calibration Mode/Off
D [31/Oct/2016:16:35:24 +0100] [Job 13] Calling FindDeviceById(cups-HP_deskjet_5100)
D [31/Oct/2016:16:35:24 +0100] [Job 13] Found device /org/freedesktop/ColorManager/devices/cups_HP_deskjet_5100
D [31/Oct/2016:16:35:24 +0100] [Job 13] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [31/Oct/2016:16:35:24 +0100] [Job 13] Calling FindDeviceById(cups-HP_deskjet_5100)
D [31/Oct/2016:16:35:24 +0100] [Job 13] Found device /org/freedesktop/ColorManager/devices/cups_HP_deskjet_5100
D [31/Oct/2016:16:35:24 +0100] [Job 13] Calling GetProfileForQualifiers(RGB.Automatic....)
D [31/Oct/2016:16:35:24 +0100] [Job 13] Failed to send: org.freedesktop.ColorManager.Device.NothingMatched:nothing matched expression \'RGB.Automatic.,RGB.Automatic.*,RGB.*.,RGB.*.*,*\'
D [31/Oct/2016:16:35:24 +0100] [Job 13] Failed to get profile filename for cups-HP_deskjet_5100
D [31/Oct/2016:16:35:24 +0100] [Job 13] Color Manager: no profiles specified in PPD
D [31/Oct/2016:16:35:24 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [31/Oct/2016:16:35:24 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [31/Oct/2016:16:35:24 +0100] [Job 13] Set job-printer-state-message to "Color Manager: no profiles specified in PPD", current level=INFO
D [31/Oct/2016:16:35:24 +0100] [Job 13] Color Manager: ICC Profile: None
D [31/Oct/2016:16:35:24 +0100] Discarding unused job-progress event...
D [31/Oct/2016:16:35:24 +0100] Discarding unused printer-state-changed event...
D [31/Oct/2016:16:35:24 +0100] [Job 13] Ghostscript using Any-Part-of-Pixel method to fill paths.
D [31/Oct/2016:16:35:24 +0100] [Job 13] Ghostscript command line: gs -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -sstdout=%stderr -sOutputFile=%stdout -sDEVICE=cups -sMediaType=Automatic -sOutputType=0 -r600x600 -dMediaPosition=7 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 -dcupsMediaType=-1 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=17 -dcupsInteger0=2 -scupsPageSizeName=Letter -I/usr/share/cups/fonts -c \'<</.HWMargins[9.000000 9.000000 9.000000 9.000000] /Margins[0 0]>>setpagedevice\' -f -_
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[0]=\"CUPS_CACHEDIR=/var/cache/cups\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[1]=\"CUPS_DATADIR=/usr/share/cups\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[2]=\"CUPS_DOCROOT=/usr/share/cups/doc\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[3]=\"CUPS_FONTPATH=/usr/share/cups/fonts\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[4]=\"CUPS_REQUESTROOT=/var/spool/cups\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[5]=\"CUPS_SERVERBIN=/usr/lib/cups\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[6]=\"CUPS_SERVERROOT=/etc/cups\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[7]=\"CUPS_STATEDIR=/run/cups\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[8]=\"HOME=/var/spool/cups/tmp\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[9]=\"PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[10]=\"SERVER_ADMIN=root@timo-t460\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[11]=\"SOFTWARE=CUPS/2.2.1\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[12]=\"TMPDIR=/var/spool/cups/tmp\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[13]=\"USER=root\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[14]=\"CUPS_MAX_MESSAGE=2047\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[15]=\"CUPS_SERVER=/run/cups/cups.sock\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[16]=\"CUPS_ENCRYPTION=IfRequested\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[17]=\"IPP_PORT=631\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[18]=\"CHARSET=utf-8\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[19]=\"LANG=en_US.UTF-8\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[20]=\"PPD=/etc/cups/ppd/HP_deskjet_5100.ppd\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[21]=\"RIP_MAX_CACHE=128m\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[22]=\"CONTENT_TYPE=application/vnd.cups-pdf-banner\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[23]=\"DEVICE_URI=hp:/usb/deskjet_5100?serial=HU36C1Y16NC3\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[24]=\"PRINTER_INFO=HP deskjet 5100\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[25]=\"PRINTER_LOCATION=\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[26]=\"PRINTER=HP_deskjet_5100\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[27]=\"PRINTER_STATE_REASONS=none\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[28]=\"CUPS_FILETYPE=document\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[29]=\"FINAL_CONTENT_TYPE=application/vnd.cups-raster\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] envp[30]=\"AUTH_INFO_REQUIRED=none\"
D [31/Oct/2016:16:35:24 +0100] [Job 13] Start rendering...
D [31/Oct/2016:16:35:24 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [31/Oct/2016:16:35:24 +0100] [Job 13] Set job-printer-state-message to "Start rendering...", current level=INFO
D [31/Oct/2016:16:35:24 +0100] [Job 13] Processing page 1...
D [31/Oct/2016:16:35:24 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:24 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [31/Oct/2016:16:35:24 +0100] [Job 13] Set job-printer-state-message to "Processing page 1...", current level=INFO
D [31/Oct/2016:16:35:24 +0100] Discarding unused job-progress event...
D [31/Oct/2016:16:35:24 +0100] Discarding unused printer-state-changed event...
D [31/Oct/2016:16:35:25 +0100] [Job 13] STATE: +connecting-to-device
D [31/Oct/2016:16:35:25 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:25 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [31/Oct/2016:16:35:25 +0100] [Job 13] PAGE: 1 1\r
D [31/Oct/2016:16:35:25 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:25 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [31/Oct/2016:16:35:25 +0100] cupsdMarkDirty(---J-)
D [31/Oct/2016:16:35:25 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [31/Oct/2016:16:35:25 +0100] Discarding unused job-progress event...
D [31/Oct/2016:16:35:25 +0100] Discarding unused printer-state-changed event...
D [31/Oct/2016:16:35:25 +0100] [Job 11] Unloading...
D [31/Oct/2016:16:35:25 +0100] [Job 13] prnt/backend/hp.c 831: INFO: open device failed stat=21: hp:/usb/deskjet_5100?serial=HU36C1Y16NC3; will retry in 30 seconds...
D [31/Oct/2016:16:35:27 +0100] [Client 49] GET /printers/HP_deskjet_5100 HTTP/1.1
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [31/Oct/2016:16:35:27 +0100] [Client 49] Read: status=200
D [31/Oct/2016:16:35:27 +0100] [Client 49] Authorized as "timo" using Basic.
D [31/Oct/2016:16:35:27 +0100] [Client 49] Processing GET /printers/HP_deskjet_5100
D [31/Oct/2016:16:35:27 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/run/cups"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@timo-t460"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/2.2.1"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[13] = "USER=root"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[15] = "CUPS_SERVER=/run/cups/cups.sock"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[19] = "LANG=en_US.UTF8"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[22] = "SERVER_NAME=127.0.0.1"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[26] = "SCRIPT_NAME=/printers/HP_deskjet_5100"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/printers/HP_deskjet_5100"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[28] = "PATH_INFO=/HP_deskjet_5100"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[29] = "REMOTE_USER=timo"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=88b1aa6a41e9639fd2af6338f41a1b2f"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:49.0) Gecko/20100101 Firefox/49.0"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [31/Oct/2016:16:35:27 +0100] [CGI] envp[34] = "QUERY_STRING="
D [31/Oct/2016:16:35:27 +0100] cupsdAddCert: Adding certificate for PID 768
D [31/Oct/2016:16:35:27 +0100] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 768)
I [31/Oct/2016:16:35:27 +0100] [Client 49] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=768, file=16)
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [CGI] org.cups.sid cookie is \"88b1aa6a41e9639fd2af6338f41a1b2f\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [Client 103] Server address is "/run/cups/cups.sock".
D [31/Oct/2016:16:35:27 +0100] [Client 103] Accepted from localhost (Domain)
D [31/Oct/2016:16:35:27 +0100] [Client 103] Waiting for request.
D [31/Oct/2016:16:35:27 +0100] [Client 103] POST / HTTP/1.1
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [Client 103] Read: status=200
D [31/Oct/2016:16:35:27 +0100] [Client 103] No authentication data provided.
D [31/Oct/2016:16:35:27 +0100] [Client 103] 2.0 CUPS-Get-Default 1
D [31/Oct/2016:16:35:27 +0100] CUPS-Get-Default
D [31/Oct/2016:16:35:27 +0100] CUPS-Get-Default client-error-not-found: No default printer.
D [31/Oct/2016:16:35:27 +0100] [Client 103] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [31/Oct/2016:16:35:27 +0100] [Client 103] Content-Length: 113
D [31/Oct/2016:16:35:27 +0100] [Client 103] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [31/Oct/2016:16:35:27 +0100] [Client 103] con->http=0x55e4b5a396f0
D [31/Oct/2016:16:35:27 +0100] [Client 103] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x55e4b5949b10(IPP_STATE_DATA), pipe_pid=0, file=-1
D [31/Oct/2016:16:35:27 +0100] [Client 103] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [31/Oct/2016:16:35:27 +0100] [Client 103] bytes=0, http_state=0, data_remaining=113
D [31/Oct/2016:16:35:27 +0100] [Client 103] Flushing write buffer.
D [31/Oct/2016:16:35:27 +0100] [Client 103] New state is HTTP_STATE_WAITING
D [31/Oct/2016:16:35:27 +0100] [Client 103] Waiting for request.
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [CGI] show_printer(http=0x5595b2111920, printer=\"HP_deskjet_5100\")
D [31/Oct/2016:16:35:27 +0100] [Client 103] POST / HTTP/1.1
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [Client 103] Read: status=200
D [31/Oct/2016:16:35:27 +0100] [Client 103] No authentication data provided.
D [31/Oct/2016:16:35:27 +0100] [Client 103] 2.0 Get-Printer-Attributes 2
D [31/Oct/2016:16:35:27 +0100] Get-Printer-Attributes ipp://localhost/printers/HP_deskjet_5100
D [31/Oct/2016:16:35:27 +0100] [Client 103] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_deskjet_5100) from localhost
D [31/Oct/2016:16:35:27 +0100] [Client 103] Content-Length: 670
D [31/Oct/2016:16:35:27 +0100] [Client 103] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [31/Oct/2016:16:35:27 +0100] [Client 103] con->http=0x55e4b5a396f0
D [31/Oct/2016:16:35:27 +0100] [Client 103] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=670, response=0x55e4b5949e20(IPP_STATE_DATA), pipe_pid=0, file=-1
D [31/Oct/2016:16:35:27 +0100] [Client 103] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [31/Oct/2016:16:35:27 +0100] [Client 103] bytes=0, http_state=0, data_remaining=670
D [31/Oct/2016:16:35:27 +0100] [Client 103] Flushing write buffer.
D [31/Oct/2016:16:35:27 +0100] [Client 103] New state is HTTP_STATE_WAITING
D [31/Oct/2016:16:35:27 +0100] [Client 103] Waiting for request.
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"127.0.0.1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"timo\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"127.0.0.1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"timo\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_state[0]=\"4\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_name[0]=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_location[0]=\"\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_info[0]=\"HP deskjet 5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: device_uri[0]=\"hp:/usb/deskjet_5100?serial=HU36C1Y16NC3\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: color_supported[0]=\"1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Deskjet 5100, hpcups 3.16.9\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: printer_commands[0]=\"none\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: refresh_page=\"10;URL=/printers/HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: TITLE=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"127.0.0.1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"timo\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] Script header: Content-Type: text/html;charset=utf-8
D [31/Oct/2016:16:35:27 +0100] [Client 49] Script header:
D [31/Oct/2016:16:35:27 +0100] [Client 49] Sending status 200 for CGI.
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [CGI] Regular expression \".*Clean.*\"
D [31/Oct/2016:16:35:27 +0100] [CGI] Regular expression \".*PrintSelfTestPage.*\"
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 103] POST / HTTP/1.1
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [Client 103] Read: status=200
D [31/Oct/2016:16:35:27 +0100] [Client 103] No authentication data provided.
D [31/Oct/2016:16:35:27 +0100] [Client 103] 2.0 Get-Jobs 3
D [31/Oct/2016:16:35:27 +0100] Get-Jobs ipp://localhost:631/printers/HP_deskjet_5100
D [31/Oct/2016:16:35:27 +0100] [Client 103] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_deskjet_5100) from localhost
D [31/Oct/2016:16:35:27 +0100] [Client 103] Content-Length: 349
D [31/Oct/2016:16:35:27 +0100] [Client 103] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [31/Oct/2016:16:35:27 +0100] [Client 103] con->http=0x55e4b5a396f0
D [31/Oct/2016:16:35:27 +0100] [Client 103] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=349, response=0x55e4b5949b10(IPP_STATE_DATA), pipe_pid=0, file=-1
D [31/Oct/2016:16:35:27 +0100] [Client 103] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [31/Oct/2016:16:35:27 +0100] [Client 103] bytes=0, http_state=0, data_remaining=349
D [31/Oct/2016:16:35:27 +0100] [Client 103] Flushing write buffer.
D [31/Oct/2016:16:35:27 +0100] [Client 103] New state is HTTP_STATE_WAITING
D [31/Oct/2016:16:35:27 +0100] [Client 103] Waiting for request.
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiClearVariables called.
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: TOTAL=\"1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"127.0.0.1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"timo\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_printer_name[0]=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: time_at_creation[0]=\"Mon 31 Oct 2016 04:35:24 PM CET\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: time_at_processing[0]=\"Mon 31 Oct 2016 04:35:24 PM CET\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_id[0]=\"13\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_state[0]=\"5\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetArray: job_printer_state_message[0]=\"Processing page 1...\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: THISURL=\"/printers/HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_deskjet_5100\"
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] [Client 103] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [31/Oct/2016:16:35:27 +0100] [Client 103] Closing connection.
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] CGI data ready to be sent.
D [31/Oct/2016:16:35:27 +0100] PID 768 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [31/Oct/2016:16:35:27 +0100] [Client 49] con->http=0x55e4b5a15810
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=768, file=16
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for CGI data.
D [31/Oct/2016:16:35:27 +0100] [Client 49] Sending 0-length chunk.
D [31/Oct/2016:16:35:27 +0100] [Client 49] Flushing write buffer.
D [31/Oct/2016:16:35:27 +0100] [Client 49] New state is HTTP_STATE_WAITING
D [31/Oct/2016:16:35:27 +0100] [Client 49] Waiting for request.
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:27 +0100] [Client 49] GET /cups.css HTTP/1.1
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [31/Oct/2016:16:35:27 +0100] [Client 49] Read: status=200
D [31/Oct/2016:16:35:27 +0100] [Client 49] Authorized as "timo" using Basic.
D [31/Oct/2016:16:35:27 +0100] [Client 49] Processing GET /cups.css
D [31/Oct/2016:16:35:27 +0100] [Client 49] filename="/usr/share/cups/doc/cups.css", type=text/css
D [31/Oct/2016:16:35:27 +0100] [Client 49] cupsdSendHeader: code=304, type="(null)", auth_type=0
D [31/Oct/2016:16:35:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [31/Oct/2016:16:35:37 +0100] [Client 49] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [31/Oct/2016:16:35:37 +0100] [Client 49] Closing connection.
D [31/Oct/2016:16:35:37 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [31/Oct/2016:16:35:44 +0100] Saving printers.conf...
I [31/Oct/2016:16:35:44 +0100] Generating printcap /etc/printcap...
I [31/Oct/2016:16:35:44 +0100] Saving job.cache...
D [31/Oct/2016:16:35:44 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"Offline
This looks suspicious:
D [31/Oct/2016:16:35:25 +0100] [Job 13] prnt/backend/hp.c 831: INFO: open device failed stat=21: hp:/usb/deskjet_5100?serial=HU36C1Y16NC3; will retry in 30 seconds...That looks like some kind of permission issue. What are the permissions on the corresponding device (should be in /dev/usb/)? What are the contents of /etc/cups/cups-files.conf?
Offline
Hi
I ran into the same problem with the ppd-file not being found. It turned out that I hadn't started cups before which caused that error, see the CUPS-Trubleshooting-Page. Maybe that helps you too.
Cheers
Offline
$ ls -l /dev/usb
$ crw-rw---- 1 root lp 180, 0 Nov 2 15:18 lp0cups-files.conf:
#
# File/directory/user/group configuration file for the CUPS scheduler.
# See "man cups-files.conf" for a complete description of this file.
#
# List of events that are considered fatal errors for the scheduler...
#FatalErrors config
# Do we call fsync() after writing configuration or status files?
#SyncOnClose No
# Default user and group for filters/backends/helper programs; this cannot be
# any user or group that resolves to ID 0 for security reasons...
#User daemon
#Group lp
# Administrator user group, used to match @SYSTEM in cupsd.conf policy rules...
# This cannot contain the Group value for security reasons...
SystemGroup sys root
# User that is substituted for unauthenticated (remote) root accesses...
#RemoteRoot remroot
# Do we allow file: device URIs other than to /dev/null?
#FileDevice No
# Permissions for configuration and log files...
#ConfigFilePerm 0640
#LogFilePerm 0644
# Location of the file logging all access to the scheduler; may be the name
# "syslog". If not an absolute path, the value of ServerRoot is used as the
# root directory. Also see the "AccessLogLevel" directive in cupsd.conf.
AccessLog /var/log/cups/access_log
# Location of cache files used by the scheduler...
#CacheDir /var/cache/cups
# Location of data files used by the scheduler...
#DataDir /usr/share/cups
# Location of the static web content served by the scheduler...
#DocumentRoot /usr/share/cups/doc
# Location of the file logging all messages produced by the scheduler and any
# helper programs; may be the name "syslog". If not an absolute path, the value
# of ServerRoot is used as the root directory. Also see the "LogLevel"
# directive in cupsd.conf.
ErrorLog /var/log/cups/error_logOffline
Unfortunately that looks exactly like it should. I only have a couple of more suggestions:
Maybe try using the usb URI instead - you might get some different error messages: usb://hp/deskjet%205100?serial=HU36C1Y16NC3
lsusb and /usr/lib/cups/backend/hp, /usr/lib/cups/backend/usb output might be helpful. The printer is potentially being accessed through a /dev/bus/usb/ node instead; perhaps check the permissions on that file?
To completely rule out permission issue, perhaps try changing the permissions on the backend (https://bbs.archlinux.org/viewtopic.php … 3#p1655533) - for both the hp and usb backends, then trying to print.
Sometimes messages show up in dmesg or in the systemd status output for the org.cups.cupsd service; perhaps post the outputs of both of those?
Finally, what happened after the 30 seconds elapsed - maybe some more messages show up in the log?
Hope that helps...
Offline