You are not logged in.

#1 2019-11-19 20:45:26

stefano
Member
Registered: 2011-04-09
Posts: 258

CUPS no longer printing to network printer

After a recent update, I am no longer able to print to a networked HP printer using CUPS/PCL (or other driver as well).
Setup:

1. Archlinux server running latest CUPS (version 2.3.0)
 
2. Archlinux client running the same CUPS as above

3. HP1320 printer connected through USB to server

After many frustrating and unsuccessful attempts to fix the situation I deleted all the old printers queues on the server and started from scratch:

a. Created a new _shared_ local/USB printer with the hpcups/PCL 3 driver

b. Allowed local network access as indicated in the wiki (and indeed unchanged from previous configuration, I believe):

...
WebInterface Yes
<Location />
  # Allow remote administration...
  Order allow,deny
  Allow from @LOCAL
</Location>
<Location /admin>
  # Allow remote administration...
  Order allow,deny
  Allow from @LOCAL
</Location>
<Location /admin/conf>
  AuthType Default
  Require user @SYSTEM
  # Allow remote access to the configuration files...
  Order allow,deny
  Allow from @LOCAL
</Location>
<Location /admin/log>
  AuthType Default
  Require user @SYSTEM
  Order allow,deny
  Allow from @LOCAL
</Location>

c. Successfully tested printer by printing a test page from CUPS web interface to server

d. Restarted cupsd service on both server and client

e. client's CUPS web interface shows remote printer no server

So far so good..., but then:

f. Tried printing a test page from client's CUPS web interface, but no output is produced

I briefly see a message (in the browser) that a job has been created, yet the job never arrives to the server and indeed does not seem to be created on the client either. Or perhaps its life is so short that it is already gone by the time i get to the jobs's page.

The error log on the server  shows that a request from the client was received, then some authentication was missing and eventually found, until a short time later the connection is closed (error 32 Broken pipe) (See error log excerpt below) . So that seems to indicate the problem is with the client/server communication exchange, but I have no idea how to track it down. On the other hand, the client's error log, seem to indicate everything went fine (see log below)

Help is greatly appreciated


=============CUPS server's and client's  error logs (fragments) ========
Here is the relevant part of the server's error log that refers to the printing attempt from the client. Server's address is 192.168.0.4, client's is 192.168.0.5

D [19/Nov/2019:09:39:08 -0600] [Client 21] Server address is "192.168.0.4".
D [19/Nov/2019:09:39:08 -0600] [Client 21] Accepted from 192.168.0.5:40710 (IPv4)
D [19/Nov/2019:09:39:08 -0600] [Client 21] Waiting for request.
D [19/Nov/2019:09:39:08 -0600] Report: clients=1
D [19/Nov/2019:09:39:08 -0600] Report: jobs=2
D [19/Nov/2019:09:39:08 -0600] Report: jobs-active=0
D [19/Nov/2019:09:39:08 -0600] Report: printers=1
D [19/Nov/2019:09:39:08 -0600] Report: stringpool-string-count=684
D [19/Nov/2019:09:39:08 -0600] Report: stringpool-alloc-bytes=9208
D [19/Nov/2019:09:39:08 -0600] Report: stringpool-total-bytes=13816
D [19/Nov/2019:09:39:08 -0600] [Client 21] POST /printers/HP_POLUS HTTP/1.1
D [19/Nov/2019:09:39:08 -0600] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=200, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] No authentication data provided.
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: Ignoring "lo".
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: Ignoring "enp3s7".
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: Ignoring "enp0s20".
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: "lo" = localhost:631
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: "enp3s7" = 192.168.0.4:631
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: "lo" = localhost:631
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: "enp3s7" = [v1.2605:a601:aa0b:ec00:8616:f9ff:fe00:73e4]:631
D [19/Nov/2019:09:39:08 -0600] cupsdNetIFUpdate: "enp3s7" = [v1.fe80::8616:f9ff:fe00:73e4+enp3s7]:631
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=100, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=100, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=100, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=100, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=100, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=100, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] Read: status=100, state=6
D [19/Nov/2019:09:39:08 -0600] [Client 21] 2.0 Get-Printer-Attributes 4076
D [19/Nov/2019:09:39:08 -0600] Get-Printer-Attributes ipps://polus.local:631/printers/HP_POLUS
D [19/Nov/2019:09:39:08 -0600] [Client 21] Returning IPP successful-ok for Get-Printer-Attributes (ipps://polus.local:631/printers/HP_POLUS) from 192.168.0.5.
D [19/Nov/2019:09:39:08 -0600] [Client 21] Content-Length: 154
D [19/Nov/2019:09:39:08 -0600] [Client 21] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Nov/2019:09:39:08 -0600] [Client 21] con->http=0x55b2a30ac8e0
D [19/Nov/2019:09:39:08 -0600] [Client 21] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=154, response=0x55b2a309c110(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Nov/2019:09:39:08 -0600] [Client 21] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Nov/2019:09:39:08 -0600] [Client 21] bytes=0, http_state=0, data_remaining=154
D [19/Nov/2019:09:39:08 -0600] [Client 21] Flushing write buffer.
D [19/Nov/2019:09:39:08 -0600] [Client 21] New state is HTTP_STATE_WAITING
D [19/Nov/2019:09:39:08 -0600] [Client 21] Waiting for request.
D [19/Nov/2019:09:39:08 -0600] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [19/Nov/2019:09:39:08 -0600] [Client 21] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [19/Nov/2019:09:39:08 -0600] [Client 21] Closing connection.

and here is the client's error log for the test page printing job

D [19/Nov/2019:14:37:49 -0600] [Job 1752] Applying default options...
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Adding default cups-browsed=true
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Adding default cups-browsed-dest-printer=\"1751 ipps://polus.local:631/printers/HP_POLUS pdf 300dpi\"
I [19/Nov/2019:14:37:49 -0600] [Job 1752] File of type application/vnd.cups-pdf-banner queued by "stefano".
D [19/Nov/2019:14:37:49 -0600] [Job 1752] hold_until=0
I [19/Nov/2019:14:37:49 -0600] [Job 1752] Queued on "HP_POLUS_PCL_polus" by "stefano".
D [19/Nov/2019:14:37:49 -0600] [Job 1752] time-at-processing=1574195869
D [19/Nov/2019:14:37:49 -0600] [Job 1752] 3 filters for job:
D [19/Nov/2019:14:37:49 -0600] [Job 1752] bannertopdf (application/vnd.cups-pdf-banner to application/pdf, cost 32)
D [19/Nov/2019:14:37:49 -0600] [Job 1752] - (application/pdf to printer/HP_POLUS_PCL_polus/application/pdf, cost 0)
D [19/Nov/2019:14:37:49 -0600] [Job 1752] - (printer/HP_POLUS_PCL_polus/application/pdf to printer/HP_POLUS_PCL_polus, cost 0)
D [19/Nov/2019:14:37:49 -0600] [Job 1752] No job-sheets attribute.
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[0]="HP_POLUS_PCL_polus"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[1]="1752"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[2]="stefano"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[3]="Test Page"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[4]="1"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[5]="job-originating-user-name=stefano job-priority=50 job-uuid=urn:uuid:a894aa22-5cb7-3115-4927-747544391ffe cups-browsed cups-browsed-dest-printer=\\\"1751\\ ipps://polus.local:631/printers/HP_POLUS\\ pdf\\ 300dpi\\\" job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1574195869 time-at-processing=1574195869 job-impressions-completed=0"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[6]="/var/spool/cups/d01752-001"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[7]="CUPS_STATEDIR=/run/cups"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[8]="HOME=/var/spool/cups/tmp"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[10]="SERVER_ADMIN=root@192.168.0.4"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[11]="SOFTWARE=CUPS/2.3.0"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[13]="USER=root"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[14]="CUPS_MAX_MESSAGE=2047"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[17]="IPP_PORT=631"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[18]="CHARSET=utf-8"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[19]="LANG=en_US.UTF-8"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[20]="PPD=/etc/cups/ppd/HP_POLUS_PCL_polus.ppd"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[21]="RIP_MAX_CACHE=128m"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[22]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[23]="DEVICE_URI=implicitclass://HP_POLUS_PCL_polus/"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[24]="PRINTER_INFO=HP POLUS PCL"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[25]="PRINTER_LOCATION=Leo"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[26]="PRINTER=HP_POLUS_PCL_polus"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[27]="PRINTER_STATE_REASONS=none"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[28]="CUPS_FILETYPE=document"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[29]="FINAL_CONTENT_TYPE=application/pdf"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] envp[30]="AUTH_I****"
I [19/Nov/2019:14:37:49 -0600] [Job 1752] Started filter /usr/lib/cups/filter/bannertopdf (PID 46051)
I [19/Nov/2019:14:37:49 -0600] [Job 1752] Started backend /usr/lib/cups/backend/implicitclass (PID 46052)
D [19/Nov/2019:14:37:49 -0600] [CGI] cgiSetArray: job_uri[0]=\"/jobs/1752\"
D [19/Nov/2019:14:37:49 -0600] [CGI] cgiSetArray: job_id[0]=\"1752\"
D [19/Nov/2019:14:37:49 -0600] Setting cups-browsed-dest-printer-default to "\"1752 ipps://polus.local:631/printers/HP_POLUS pdf 300dpi\""...
D [19/Nov/2019:14:37:49 -0600] [Job 1752] PDF template file doesn\'t have form. It\'s okay.
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Read cups-browsed-dest-printer option: \"1752 ipps://polus.local:631/printers/HP_POLUS pdf 300dpi\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Received destination host name from cups-browsed: printer-uri ipps://polus.local:631/printers/HP_POLUS pdf 300dpi
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Received job for the printer with the destination uri - ipps://polus.local:631/printers/HP_POLUS, Final-document format for the printer - pdf and requested resolution - 300dpi
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Debug: implicitclass - copying to temp print file \"/var/spool/cups/tmp/0b3e45ddd860b\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Removing cups-browsed-dest-printer option from arguments
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Removing option cups-browsed if it is present
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Changed the argv[5] to job-originating-user-name=stefano job-priority=50 job-uuid=urn:uuid:a894aa22-5cb7-3115-4927-747544391ffe job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1574195869 time-at-processing=1574195869 job-impressions-completed=0 output-format=pdf Resolution=300dpi
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Printer supports output formats: pdf
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Using following CUPS filter chain to convert input data to the PDF format: gziptoany
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[0]=\"implicitclass://HP_POLUS_PCL_polus/\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[1]=\"1752\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[2]=\"stefano\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[3]=\"Test Page\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[4]=\"1\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[5]=\"job-originating-user-name=stefano job-priority=50 job-uuid=urn:uuid:a894aa22-5cb7-3115-4927-747544391ffe job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1574195869 time-at-processing=1574195869 job-impressions-completed=0 output-format=pdf Resolution=300dpi page-logging=on\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] argv[6]=\"/var/spool/cups/tmp/0b3e45ddd860b\"
D [19/Nov/2019:14:37:49 -0600] [Job 1752] gziptoany (PID 46053) started.
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Set job-printer-state-message to "gziptoany (PID 46053) started.", current level=INFO
D [19/Nov/2019:14:37:49 -0600] [Job 1752] PID 46051 (/usr/lib/cups/filter/bannertopdf) exited with no errors.
D [19/Nov/2019:14:37:49 -0600] [Job 1752] gziptoany (PID 46053) exited with no errors.
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Set job-printer-state-message to "gziptoany (PID 46053) exited with no errors.", current level=INFO
D [19/Nov/2019:14:37:49 -0600] [Job 1752] The filtered output of pdftoippprinter is written to file /var/spool/cups/tmp/0b3e45ddd8691
D [19/Nov/2019:14:37:49 -0600] [Job 1752] Started IPP Backend with pid: 46054
D [19/Nov/2019:14:37:49 -0600] [Job 1752] The IPP Backend exited with the status 0
D [19/Nov/2019:14:37:49 -0600] [Job 1752] PID 46052 (/usr/lib/cups/backend/implicitclass) exited with no errors.
D [19/Nov/2019:14:37:49 -0600] [Job 1752] time-at-completed=1574195869
I [19/Nov/2019:14:37:49 -0600] [Job 1752] Job completed.
D [19/Nov/2019:14:37:50 -0600] [Job 1752] Unloading...

Last edited by stefano (2019-11-19 21:24:28)

Offline

#2 2019-11-20 17:15:22

stefano
Member
Registered: 2011-04-09
Posts: 258

Re: CUPS no longer printing to network printer

UPDATE:

after many unsuccessful attempts to fix the cups installation on the client, I was finally able to print by bypassing it altogether, following the libcups methods (no local CUPS server) suggested in the wiki even though it seems to be deprecated by the CUPS developers[1], but most of the reasons given (network down, client (i.e. laptop) physically moving to a new location, etc.)  do not apply to my scenario (desktop printing on a local reliable network, no VPN, etc.). 

I'm leaving the issue as unsolved as I would prefer to control my print jobs through the Web interface and I am still hopeful for a solution along those lines.

[1] https://lists.cups.org/pipermail/cups/2 … 27231.html

Last edited by stefano (2019-11-20 17:21:29)

Offline

#3 2020-05-23 09:46:32

magillos
Member
Registered: 2010-07-03
Posts: 34

Re: CUPS no longer printing to network printer

I have a similar issue but strangely I am able to print from Firefox. It fails whenever I try to print from Kde programs or LibreOffice. Server doesn't even pick up the job and the client says:

Get-Printer-Attributes client-error-not-found: The printer or class does notGet-Printer-Attributes client-error-not-found: The printer or class does not exist.

and

Returning IPP client-error-not-found for Get-Printer-Attributes from localhost

Thanks for libcups workaround.

Offline

#4 2020-05-23 15:31:38

stefano
Member
Registered: 2011-04-09
Posts: 258

Re: CUPS no longer printing to network printer

I haven't looked again at the issue since I found the libcups workaround, but I can confirm that my problem is, like yours, with KDE. Or rather, with Plasma, I would say. I can print from KDE apps (e.g. Okular) if I launch them from the command line, but not if they're launched from another app (e.g. Dolphin). So for instance, if I double click on a pdf file in Dolphin I can't print from the Okular app that Dolphin launched. But if I open Okular on the same file from Konsole everything is fine.

Looking at cups's error log for the former behavior (printing from Okular launched from Dolphin), it seems the daemon gets into a loop, with numerous repetitions of this block:

D [23/May/2020:10:21:29 -0500] [Client 24] Waiting for request.
D [23/May/2020:10:21:29 -0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/May/2020:10:21:30 -0500] [Job 1789] IPP/2.0 Get-Printer-Attributes #609
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- operation-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-charset charset utf-8
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-natural-language naturalLanguage en
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-uri uri ipp://polus.local:631/printers/HP_POLUS
I [23/May/2020:10:21:30 -0500] Expiring subscriptions...
D [23/May/2020:10:21:30 -0500] [Job 1789] requesting-user-name nameWithoutLanguage stefano
D [23/May/2020:10:21:30 -0500] [Job 1789] requested-attributes 1setOf keyword compression-supported,copies-supported,cups-version,document-format-supported,job-password-encryption-supported,marker-colors,marker-high-levels,marker-levels,marker-low-levels,marker-message,marker-names,marker-types,media-col-supported,multiple-document-handling-supported,operations-supported,print-color-mode-supported,printer-alert,printer-alert-description,printer-is-accepting-jobs,printer-mandatory-job-attributes,printer-state,printer-state-message,printer-state-reasons
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- end-of-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] IPP/2.0 Get-Printer-Attributes #610
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- operation-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-charset charset utf-8
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-natural-language naturalLanguage en
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-uri uri ipp://polus.local:631/printers/HP_POLUS
D [23/May/2020:10:21:30 -0500] [Job 1789] requesting-user-name nameWithoutLanguage stefano
D [23/May/2020:10:21:30 -0500] [Job 1789] requested-attributes 1setOf keyword compression-supported,copies-supported,cups-version,document-format-supported,job-password-encryption-supported,marker-colors,marker-high-levels,marker-levels,marker-low-levels,marker-message,marker-names,marker-types,media-col-supported,multiple-document-handling-supported,operations-supported,print-color-mode-supported,printer-alert,printer-alert-description,printer-is-accepting-jobs,printer-mandatory-job-attributes,printer-state,printer-state-message,printer-state-reasons
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- end-of-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] Filter failed
D [23/May/2020:10:21:30 -0500] [Job 1789] update_reasons(attr=1(none), s=\"(null)\")
D [23/May/2020:10:21:30 -0500] [Job 1789] Get-Printer-Attributes: successful-ok (successful-ok)
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- operation-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-charset charset utf-8
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-natural-language naturalLanguage en
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- printer-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-is-accepting-jobs boolean true
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-state enum idle
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-state-message textWithoutLanguage Filter failed
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-state-reasons keyword none
D [23/May/2020:10:21:30 -0500] [Job 1789] document-format-supported 1setOf mimeMediaType application/octet-stream,application/pdf,application/postscript,application/vnd.adobe-reader-postscript,application/vnd.cups-pdf,application/vnd.cups-pdf-banner,application/vnd.cups-postscript,application/vnd.cups-raster,application/vnd.cups-raw,application/x-cshell,application/x-csource,application/x-perl,application/x-shell,image/gif,image/jpeg,image/png,image/pwg-raster,image/tiff,image/urf,image/x-bitmap,image/x-photocd,image/x-portable-anymap,image/x-portable-bitmap,image/x-portable-graymap,image/x-portable-pixmap,image/x-sgi-rgb,image/x-sun-raster,image/x-xbitmap,image/x-xpixmap,image/x-xwindowdump,text/css,text/html,text/plain
D [23/May/2020:10:21:30 -0500] [Job 1789] print-color-mode-supported 1setOf keyword monochrome,color
D [23/May/2020:10:21:30 -0500] [Job 1789] compression-supported 1setOf keyword none,gzip
D [23/May/2020:10:21:30 -0500] [Job 1789] copies-supported rangeOfInteger 1-9999
D [23/May/2020:10:21:30 -0500] [Job 1789] cups-version textWithoutLanguage 2.3.3
D [23/May/2020:10:21:30 -0500] [Job 1789] media-col-supported 1setOf keyword media-bottom-margin,media-left-margin,media-right-margin,media-size,media-source,media-top-margin,media-type
D [23/May/2020:10:21:30 -0500] [Job 1789] multiple-document-handling-supported 1setOf keyword separate-documents-uncollated-copies,separate-documents-collated-copies
D [23/May/2020:10:21:30 -0500] [Job 1789] operations-supported 1setOf enum Print-Job,Validate-Job,Create-Job,Send-Document,Cancel-Job,Get-Job-Attributes,Get-Jobs,Get-Printer-Attributes,Hold-Job,Release-Job,Pause-Printer,Resume-Printer,Purge-Jobs,Set-Printer-Attributes,Set-Job-Attributes,Get-Printer-Supported-Values,Create-Printer-Subscriptions,Create-Job-Subscriptions,Get-Subscription-Attributes,Get-Subscriptions,Renew-Subscription,Cancel-Subscription,Get-Notifications,Enable-Printer,Disable-Printer,Hold-New-Jobs,Release-Held-New-Jobs,Cancel-Jobs,Cancel-My-Jobs,Close-Job,CUPS-Get-Default,CUPS-Get-Printers,CUPS-Add-Modify-Printer,CUPS-Delete-Printer,CUPS-Get-Classes,CUPS-Add-Modify-Class,CUPS-Delete-Class,CUPS-Accept-Jobs,CUPS-Reject-Jobs,CUPS-Set-Default,CUPS-Get-Devices,CUPS-Get-PPDs,CUPS-Move-Job,CUPS-Authenticate-Job,CUPS-Get-PPD,CUPS-Get-Document,Restart-Job
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- end-of-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] IPP/2.0 Get-Job-Attributes #611
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- operation-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-charset charset utf-8
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-natural-language naturalLanguage en
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-uri uri ipp://polus.local:631/printers/HP_POLUS
D [23/May/2020:10:21:30 -0500] [Job 1789] job-id integer 346
D [23/May/2020:10:21:30 -0500] [Job 1789] requesting-user-name nameWithoutLanguage stefano
D [23/May/2020:10:21:30 -0500] [Job 1789] requested-attributes 1setOf keyword job-id,job-impressions-completed,job-media-sheets-completed,job-name,job-originating-user-name,job-state,job-state-reasons
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- end-of-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] Filter failed
D [23/May/2020:10:21:30 -0500] [Job 1789] update_reasons(attr=1(none), s=\"(null)\")
D [23/May/2020:10:21:30 -0500] [Job 1789] Get-Printer-Attributes: successful-ok (successful-ok)
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- operation-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-charset charset utf-8
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-natural-language naturalLanguage en
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- printer-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-is-accepting-jobs boolean true
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-state enum idle
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-state-message textWithoutLanguage Filter failed
D [23/May/2020:10:21:30 -0500] [Job 1789] printer-state-reasons keyword none
D [23/May/2020:10:21:30 -0500] [Job 1789] document-format-supported 1setOf mimeMediaType application/octet-stream,application/pdf,application/postscript,application/vnd.adobe-reader-postscript,application/vnd.cups-pdf,application/vnd.cups-pdf-banner,application/vnd.cups-postscript,application/vnd.cups-raster,application/vnd.cups-raw,application/x-cshell,application/x-csource,application/x-perl,application/x-shell,image/gif,image/jpeg,image/png,image/pwg-raster,image/tiff,image/urf,image/x-bitmap,image/x-photocd,image/x-portable-anymap,image/x-portable-bitmap,image/x-portable-graymap,image/x-portable-pixmap,image/x-sgi-rgb,image/x-sun-raster,image/x-xbitmap,image/x-xpixmap,image/x-xwindowdump,text/css,text/html,text/plain
D [23/May/2020:10:21:30 -0500] [Job 1789] print-color-mode-supported 1setOf keyword monochrome,color
D [23/May/2020:10:21:30 -0500] [Job 1789] compression-supported 1setOf keyword none,gzip
D [23/May/2020:10:21:30 -0500] [Job 1789] copies-supported rangeOfInteger 1-9999
D [23/May/2020:10:21:30 -0500] [Job 1789] cups-version textWithoutLanguage 2.3.3
D [23/May/2020:10:21:30 -0500] [Job 1789] media-col-supported 1setOf keyword media-bottom-margin,media-left-margin,media-right-margin,media-size,media-source,media-top-margin,media-type
D [23/May/2020:10:21:30 -0500] [Job 1789] multiple-document-handling-supported 1setOf keyword separate-documents-uncollated-copies,separate-documents-collated-copies
D [23/May/2020:10:21:30 -0500] [Job 1789] operations-supported 1setOf enum Print-Job,Validate-Job,Create-Job,Send-Document,Cancel-Job,Get-Job-Attributes,Get-Jobs,Get-Printer-Attributes,Hold-Job,Release-Job,Pause-Printer,Resume-Printer,Purge-Jobs,Set-Printer-Attributes,Set-Job-Attributes,Get-Printer-Supported-Values,Create-Printer-Subscriptions,Create-Job-Subscriptions,Get-Subscription-Attributes,Get-Subscriptions,Renew-Subscription,Cancel-Subscription,Get-Notifications,Enable-Printer,Disable-Printer,Hold-New-Jobs,Release-Held-New-Jobs,Cancel-Jobs,Cancel-My-Jobs,Close-Job,CUPS-Get-Default,CUPS-Get-Printers,CUPS-Add-Modify-Printer,CUPS-Delete-Printer,CUPS-Get-Classes,CUPS-Add-Modify-Class,CUPS-Delete-Class,CUPS-Accept-Jobs,CUPS-Reject-Jobs,CUPS-Set-Default,CUPS-Get-Devices,CUPS-Get-PPDs,CUPS-Move-Job,CUPS-Authenticate-Job,CUPS-Get-PPD,CUPS-Get-Document,Restart-Job
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- end-of-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] (monitor) Get-Job-Attributes: successful-ok (successful-ok)
D [23/May/2020:10:21:30 -0500] [Job 1789] (monitor) job-state = processing-stopped
D [23/May/2020:10:21:30 -0500] [Job 1789] (monitor) job-state = processing-stopped
D [23/May/2020:10:21:30 -0500] [Job 1789] Get-Job-Attributes: successful-ok (successful-ok)
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- operation-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-charset charset utf-8
D [23/May/2020:10:21:30 -0500] [Job 1789] attributes-natural-language naturalLanguage en
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- job-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] job-originating-user-name nameWithoutLanguage stefano
D [23/May/2020:10:21:30 -0500] [Job 1789] job-name nameWithoutLanguage Layout 1
D [23/May/2020:10:21:30 -0500] [Job 1789] job-id integer 346
D [23/May/2020:10:21:30 -0500] [Job 1789] job-state enum processing-stopped
D [23/May/2020:10:21:30 -0500] [Job 1789] job-state-reasons keyword job-completed-with-errors
D [23/May/2020:10:21:30 -0500] [Job 1789] job-impressions-completed integer 0
D [23/May/2020:10:21:30 -0500] [Job 1789] job-media-sheets-completed integer 0
D [23/May/2020:10:21:30 -0500] [Job 1789] ---- end-of-attributes-tag ----
D [23/May/2020:10:21:30 -0500] [Job 1789] update_reasons(attr=0(), s=\"+cups-remote-stopped\")
D [23/May/2020:10:21:30 -0500] [Job 1789] PAGE: total 0
D [23/May/2020:10:21:30 -0500] cupsdMarkDirty(----S)
D [23/May/2020:10:21:30 -0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/May/2020:10:21:30 -0500] cupsdMarkDirty(---J-)
D [23/May/2020:10:21:30 -0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/May/2020:10:21:30 -0500] [Notifier] state=3
D [23/May/2020:10:21:30 -0500] [Notifier] JobProgress
D [23/May/2020:10:21:30 -0500] [Notifier] state=3

I see a couple of "Filter failed" lines, but I can't figure out the reasons that caused the failures.

Offline

#5 2020-05-23 20:09:46

magillos
Member
Registered: 2010-07-03
Posts: 34

Re: CUPS no longer printing to network printer

It doesn't matter in my case how I run the program, from terminal or dolphin. I get the same errors. With libcups method and environment variable set up in ~/.pam_environment remote printing works fine and regardless how I start the program. Also libcups disadvantages aren't really problematic in may case and I can still use cups server if I want to print from devices other than the Arch run laptop.

My logs look bit different though:

D [23/May/2020:20:57:33 +0100] [Client 7] Read: status=200, state=6
D [23/May/2020:20:57:33 +0100] [Client 7] No authentication data provided.
D [23/May/2020:20:57:33 +0100] [Client 7] 2.0 Get-Printer-Attributes 68
D [23/May/2020:20:57:33 +0100] Get-Printer-Attributes ipp://localhost/printers/HP_Photosmart_C4200_series_osmc
D [23/May/2020:20:57:33 +0100] [Client 7] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Photosmart_C4200_series_osmc) from localhost.
D [23/May/2020:20:57:33 +0100] [Client 7] Content-Length: 98
D [23/May/2020:20:57:33 +0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
I [23/May/2020:20:57:33 +0100] Expiring subscriptions...
D [23/May/2020:20:57:33 +0100] cupsdMarkDirty(P----)
D [23/May/2020:20:57:33 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [23/May/2020:20:57:33 +0100] cupsdDeregisterPrinter(p=0x55ba88747a80(HP_Photosmart_C4200_series_osmc), removeit=1)
D [23/May/2020:20:57:33 +0100] Calling FindDeviceById(cups-HP_Photosmart_C4200_series_osmc)
D [23/May/2020:20:57:33 +0100] FindDeviceById failed: org.freedesktop.ColorManager.NotFound:device id \'cups-HP_Photosmart_C4200_series_osmc\' does not exist
D [23/May/2020:20:57:33 +0100] [Client 7] con->http=0x55ba887443e0
D [23/May/2020:20:57:33 +0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=98, response=0x55ba88748f20(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/May/2020:20:57:33 +0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/May/2020:20:57:33 +0100] [Client 7] bytes=0, http_state=0, data_remaining=98
D [23/May/2020:20:57:33 +0100] [Client 7] Flushing write buffer.
D [23/May/2020:20:57:33 +0100] [Client 7] New state is HTTP_STATE_WAITING
D [23/May/2020:20:57:33 +0100] [Client 7] Waiting for request.
D [23/May/2020:20:57:33 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [23/May/2020:20:57:34 +0100] [Client 7] POST / HTTP/1.1
D [23/May/2020:20:57:34 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [23/May/2020:20:57:34 +0100] [Client 7] Read: status=200, state=6
D [23/May/2020:20:57:34 +0100] [Client 7] No authentication data provided.
D [23/May/2020:20:57:34 +0100] [Client 7] 2.0 Get-Printer-Attributes 69
D [23/May/2020:20:57:34 +0100] Get-Printer-Attributes ipp://localhost/printers/HP_Photosmart_C4200_series_osmc
D [23/May/2020:20:57:34 +0100] Get-Printer-Attributes client-error-not-found: The printer or class does not exist.
D [23/May/2020:20:57:34 +0100] [Client 7] Returning IPP client-error-not-found for Get-Printer-Attributes (ipp://localhost/printers/HP_Photosmart_C4200_series_osmc) from localhost.
D [23/May/2020:20:57:34 +0100] [Client 7] Content-Length: 130
D [23/May/2020:20:57:34 +0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
I [23/May/2020:20:57:34 +0100] Expiring subscriptions...
D [23/May/2020:20:57:34 +0100] [Client 7] con->http=0x55ba887443e0
D [23/May/2020:20:57:34 +0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=130, response=0x55ba88748e90(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/May/2020:20:57:34 +0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/May/2020:20:57:34 +0100] [Client 7] bytes=0, http_state=0, data_remaining=130
D [23/May/2020:20:57:34 +0100] [Client 7] Flushing write buffer.
D [23/May/2020:20:57:34 +0100] [Client 7] New state is HTTP_STATE_WAITING
D [23/May/2020:20:57:34 +0100] [Client 7] Waiting for request.
D [23/May/2020:20:57:34 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [23/May/2020:20:57:34 +0100] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/May/2020:20:57:34 +0100] [Client 7] Closing connection.
D [23/May/2020:20:57:34 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [23/May/2020:20:57:34 +0100] [Client 6] POST /printers/HP_Photosmart_C4200_series_osmc HTTP/1.1
D [23/May/2020:20:57:34 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [23/May/2020:20:57:34 +0100] [Client 6] Read: status=200, state=6
D [23/May/2020:20:57:34 +0100] [Client 6] No authentication data provided.
D [23/May/2020:20:57:34 +0100] [Client 6] 2.0 Get-Printer-Attributes 70
D [23/May/2020:20:57:34 +0100] Get-Printer-Attributes ipp://localhost/printers/HP_Photosmart_C4200_series_osmc
D [23/May/2020:20:57:34 +0100] Get-Printer-Attributes client-error-not-found: The printer or class does not exist.
D [23/May/2020:20:57:34 +0100] [Client 6] Returning IPP client-error-not-found for Get-Printer-Attributes (ipp://localhost/printers/HP_Photosmart_C4200_series_osmc) from localhost.
D [23/May/2020:20:57:34 +0100] [Client 6] Content-Length: 130
D [23/May/2020:20:57:34 +0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/May/2020:20:57:34 +0100] [Client 6] con->http=0x55ba8873fb80
D [23/May/2020:20:57:34 +0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=130, response=0x55ba88748e20(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/May/2020:20:57:34 +0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/May/2020:20:57:34 +0100] [Client 6] bytes=0, http_state=0, data_remaining=130
D [23/May/2020:20:57:34 +0100] [Client 6] Flushing write buffer.
D [23/May/2020:20:57:34 +0100] [Client 6] New state is HTTP_STATE_WAITING
D [23/May/2020:20:57:34 +0100] [Client 6] Waiting for request.
D [23/May/2020:20:57:34 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [23/May/2020:20:57:34 +0100] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/May/2020:20:57:34 +0100] [Client 6] Closing connection.
D [23/May/2020:20:57:34 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [23/May/2020:20:57:35 +0100] Expiring subscriptions...
I [23/May/2020:20:58:04 +0100] Saving printers.conf...
D [23/May/2020:20:58:04 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [23/May/2020:20:58:04 +0100] Expiring subscriptions...

[Update] I don't know if it will be relevant for you but I manged to make it work. Arch Wiki mentions the need of setting up clients as raw device to avoid using filters twice. I didn't think it applied to my case as I was trying to send print jobs directly to server printer. But after adding network discovered printer as Make 'Raw' and Model 'Raw Queue' on the client side I'm finally able to send jobs through it and print from any program.

Last edited by magillos (2020-05-27 08:10:04)

Offline

Board footer

Powered by FluxBB