Bug 2180752

Summary: cups reports: "The printer may not exist or is unavailable at this time" and the printer is permanently disabled
Product: [Fedora] Fedora Reporter: Albert Flügel <af>
Component: cupsAssignee: Zdenek Dohnal <zdohnal>
Status: CLOSED NOTABUG QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: low Docs Contact:
Priority: unspecified    
Version: 37CC: twaugh, zdohnal
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-03-22 12:22:58 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Albert Flügel 2023-03-22 08:05:37 UTC
Description of problem:
Yesterday out of the nothing i had this problem on Fedora 37:
https://askubuntu.com/questions/1411604/status-the-printer-may-not-exist-or-is-unavailable-at-this-time

cups reported the (network, hpdirect port 9100) printer as unavailable. Restarting cups, the system or the printer did not help. I had to explicitely enable the printer again (via the web interface)

Version-Release number of selected component (if applicable):
2.4.2-10.fc37

How reproducible:
unclear.

Steps to Reproduce:
1. use your system for a sufficiently long time

Actual results:
Printer unavailable

Expected results:
Printer gets the job from cups.

Additional info:
In the syslog i see:
Mar 19 10:43:31 darkstar cupsd[867]: REQUEST localhost - - "POST / HTTP/1.1" 200 18
2 Renew-Subscription client-error-not-found
Mar 19 12:25:24 darkstar cupsd[867]: REQUEST localhost - - "POST / HTTP/1.1" 200 18
2 Renew-Subscription client-error-not-found
Mar 20 19:17:58 darkstar cupsd[867]: REQUEST localhost - - "POST / HTTP/1.1" 200 18
2 Renew-Subscription client-error-not-found
Mar 21 19:44:26 darkstar cupsd[867]: REQUEST localhost - - "POST /printers/bunti HTTP/1.1" 200 173825 Print-Job successful-ok
                                               Module libcups.so.2 with build-id 974782de2c576bfacb0d6b8c72c791d544b8a66f
                                               Metadata for module libcups.so.2 owned by FDO found: {
                                                       "name" : "cups",
Mar 21 19:45:00 darkstar cupsd[867]: [Job 278] The printer is unreachable at this time.
Mar 21 19:45:08 darkstar cupsd[867]: REQUEST localhost - - "POST /printers/bunti HTTP/1.1" 200 178158 Print-Job successful-ok
Mar 21 19:45:35 darkstar cupsd[867]: [Job 278] The printer is unreachable at this time.
Mar 21 19:46:15 darkstar cupsd[867]: [Job 278] The printer is unreachable at this time.
Mar 21 19:49:16 darkstar cupsd[867]: [Job 278] Unable to write print data: Broken pipe
Mar 21 19:49:16 darkstar cupsd[867]: bunti alb 278 [21/Mar/2023:19:49:16 +0100] total 2 - localhost Document from  - -
Mar 21 19:49:16 darkstar cupsd[867]: [Job 278] Backend returned status 1 (failed)
Mar 21 19:51:42 darkstar systemd[1]: Stopping cups.service - CUPS Scheduler...
Mar 21 19:51:42 darkstar systemd[1]: cups.service: Deactivated successfully.
Mar 21 19:51:42 darkstar systemd[1]: Stopped cups.service - CUPS Scheduler.
Mar 21 19:51:42 darkstar systemd[1]: cups.service: Consumed 7.456s CPU time.
Mar 21 19:51:42 darkstar systemd[1]: cups.path: Deactivated successfully.
Mar 21 19:51:42 darkstar systemd[1]: Stopped cups.path - CUPS Scheduler.
Mar 21 19:51:42 darkstar systemd[1]: Stopping cups.path - CUPS Scheduler...
Mar 21 19:51:42 darkstar systemd[1]: Started cups.path - CUPS Scheduler.
Mar 21 19:51:42 darkstar systemd[1]: cups.socket: Deactivated successfully.
Mar 21 19:51:42 darkstar systemd[1]: Closed cups.socket - CUPS Scheduler.
Mar 21 19:51:42 darkstar audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=cups comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 21 19:51:42 darkstar systemd[1]: Stopping cups.socket - CUPS Scheduler...
Mar 21 19:51:42 darkstar systemd[1]: Listening on cups.socket - CUPS Scheduler.
Mar 21 19:51:42 darkstar systemd[1]: Starting cups.service - CUPS Scheduler...
Mar 21 19:51:42 darkstar cupsd[64922]: Unknown directive BrowseAllow on line 20 of /etc/cups/cupsd.conf.
Mar 21 19:51:42 darkstar cupsd[64922]: Unknown directive BrowseOrder on line 21 of /etc/cups/cupsd.conf.
Mar 21 19:51:42 darkstar cupsd[64922]: Unknown directive BrowseRemoteProtocols on line 22 of /etc/cups/cupsd.conf.
Mar 21 19:51:42 darkstar cupsd[64922]: Printer drivers are deprecated and will stop working in a future version of CUPS. See https://github.com/OpenPrinting/cups/issues/103
Mar 21 19:51:42 darkstar audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=cups comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 21 19:51:42 darkstar systemd[1]: Started cups.service - CUPS Scheduler.
Mar 21 19:54:08 darkstar audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=cups comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 21 19:54:08 darkstar systemd[1]: Stopping cups.service - CUPS Scheduler...
Mar 21 19:54:08 darkstar systemd[1]: cups.service: Deactivated successfully.
Mar 21 19:54:08 darkstar systemd[1]: Stopped cups.service - CUPS Scheduler.
Mar 21 19:54:08 darkstar systemd[1]: cups.service: Consumed 2.057s CPU time.
Mar 21 19:54:10 darkstar systemd[1]: cups.path: Deactivated successfully.
Mar 21 19:54:10 darkstar systemd[1]: Stopped cups.path - CUPS Scheduler.
Mar 21 19:54:10 darkstar systemd[1]: cups.socket: Deactivated successfully.
Mar 21 19:54:10 darkstar systemd[1]: Closed cups.socket - CUPS Scheduler.
Mar 21 19:55:02 darkstar systemd[1]: Started cups.path - CUPS Scheduler.
Mar 21 19:55:02 darkstar systemd[1]: Listening on cups.socket - CUPS Scheduler.
Mar 21 19:55:04 darkstar systemd[1]: Starting cups.service - CUPS Scheduler...
Mar 21 19:55:05 darkstar cupsd[886]: Unknown directive BrowseAllow on line 20 of /etc/cups/cupsd.conf.
Mar 21 19:55:05 darkstar cupsd[886]: Unknown directive BrowseOrder on line 21 of /etc/cups/cupsd.conf.
Mar 21 19:55:05 darkstar cupsd[886]: Unknown directive BrowseRemoteProtocols on line 22 of /etc/cups/cupsd.conf.
Mar 21 19:55:05 darkstar cupsd[886]: Printer drivers are deprecated and will stop working in a future version of CUPS. See https://github.com/OpenPrinting/cups/issues/103
Mar 21 19:55:06 darkstar systemd[1]: Started cups.service - CUPS Scheduler.
Mar 21 19:55:06 darkstar audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=cups comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 21 19:55:17 darkstar cupsd[886]: REQUEST localhost - - "POST / HTTP/1.1" 200 359 Create-Printer-Subscriptions successful-ok
Mar 21 19:55:38 darkstar cupsd[886]: REQUEST localhost - - "POST / HTTP/1.1" 200 359 Create-Printer-Subscriptions successful-ok
Mar 21 19:55:45 darkstar cupsd[886]: REQUEST localhost - - "POST / HTTP/1.1" 200 151 Cancel-Subscription successful-ok
...

However, the still queued job is not printed. Printer is reported unavailable.
BTW. why was it necessary to abolish options BrowseRemoteProtocols etc., that were even crucial in earlier versions ? And what does it mean "Printer drivers are deprecated and will stop working in a future version of CUPS" ? I've read the articla, but it is not getting clear to me, what is meant by "driver" - for my perception a fuzzy term since the early days microsoft called everything a "driver" that had to do with anything outside the os.
And i want to know, how much effort went during the last 5 years into what is going to be abolished thus breaking lots of existing setups.

Comment 1 Zdenek Dohnal 2023-03-22 12:22:58 UTC
Hi,

your print job failed:

Mar 21 19:46:15 darkstar cupsd[867]: [Job 278] The printer is unreachable at this time.
Mar 21 19:49:16 darkstar cupsd[867]: [Job 278] Unable to write print data: Broken pipe
Mar 21 19:49:16 darkstar cupsd[867]: bunti alb 278 [21/Mar/2023:19:49:16 +0100] total 2 - localhost Document from  - -
Mar 21 19:49:16 darkstar cupsd[867]: [Job 278] Backend returned status 1 (failed)

which disables the print queue by default - this is configurable by ErrorPolicy directive in cupsd.conf. The default is set like this to don't lose the job and prevent failures of other jobs in the queue - once user fixes the problem, he can reenable the queue, resubmits the job and the job and others in the queues get printed.

(In reply to Albert Flügel from comment #0)
> BTW. why was it necessary to abolish options BrowseRemoteProtocols etc.,
> that were even crucial in earlier versions ? 

They are no longer used by CUPS for various reasons - f.e. BrowseRemoteProtocol is removed from CUPS because there is only one way how to look for printers via a protocol - mDNS - and this is used everytime when there is avahi-daemon running.

Btw the option was removed from cupsd.conf during cups-filters creation, more than 10 years ago.

>And what does it mean "Printer
> drivers are deprecated and will stop working in a future version of CUPS" ?
> I've read the articla, but it is not getting clear to me, what is meant by
> "driver" - for my perception a fuzzy term since the early days microsoft
> called everything a "driver" that had to do with anything outside the os.

Printer drivers are PPD files+filters+non-IPP backends. To keep it simple, the driver support is just moved from CUPS to printer applications, so in case you have to use a driver, you install the printer in printer application - CUPS is able to pick up the service which shared from the printer application.

> And i want to know, how much effort went during the last 5 years into what
> is going to be abolished thus breaking lots of existing setups.

This effort lasts over 10 years and printer drivers and their CUPS PPD API are deprecated for most of that time. OpenPrintning and PWG groups did a great job with this - the whole printer application design was brought by them, so users don't have to throw away their old printers - and the groups made it while dealing supporting the current use cases.

There are docs regarding how to find out whether your printer is capable of using driverless stuff - https://docs.fedoraproject.org/en-US/quick-docs/cups-useful-tricks/#_how_to_find_out_whether_my_printer_is_capable_of_driverless_printing and several user stories how to install printers nowadays https://docs.fedoraproject.org/en-US/quick-docs/cups-useful-tricks/#_how_to_install_a_print_queue .