Bug 1621949 - cups is Unable to get printer status
Summary: cups is Unable to get printer status
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: cups
Version: 28
Hardware: Unspecified
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Zdenek Dohnal
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: 1625913
TreeView+ depends on / blocked
 
Reported: 2018-08-24 03:02 UTC by Andrew Schorr
Modified: 2018-11-01 13:39 UTC (History)
6 users (show)

Fixed In Version: cups-2.2.6-22.fc28
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-09-11 16:54:29 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
debug log (9.83 KB, application/x-gzip)
2018-08-29 19:59 UTC, Andrew Schorr
no flags Details

Description Andrew Schorr 2018-08-24 03:02:41 UTC
Description of problem: After upgrading cups to the latest version, it is unable to print. It consistently gives the error "Unable to get printer status" for my network printer. Downgrading to version cups-2.2.6-14.fc28.x86_64 fixes the problem.


Version-Release number of selected component (if applicable):
cups-2.2.6-18.fc28.x86_64


How reproducible:
try to print something. 

Steps to Reproduce:
1. dnf upgrade cups
2. lpr /etc/passwd
3. lpstat -t

Actual results:
scheduler is running
system default destination: Epson-XP-830
device for Epson-XP-830: ipp://epson-xp-830/ipp/print
Epson-XP-830 accepting requests since Thu 23 Aug 2018 10:57:58 PM EDT
printer Epson-XP-830 now printing Epson-XP-830-171.  enabled since Thu 23 Aug 2018 10:57:58 PM EDT
        Unable to get printer status.
Epson-XP-830-171        schorr            1024   Thu 23 Aug 2018 10:57:58 PM EDT


Expected results:
It should print the document instead of hanging. I tried disabling and reenabling the printer, and that didn't help. Downgrading cups fixed the problem. This is an Epson XP-830 network printer.


Additional info:

Comment 1 Zdenek Dohnal 2018-08-28 10:37:33 UTC
Hi Andrew,

thank you for reporting this issue! I think you encountered issue with TLS, which the last update enhanced this functionality. Would you mind trying to downgrade cups?

Comment 2 Andrew Schorr 2018-08-29 12:14:12 UTC
As my report said, I did downgrade to cups-2.2.6-14.fc28.x86_64, and that fixed the problem. Are you asking me to downgrade to 2.2.6-17?

Comment 3 Zdenek Dohnal 2018-08-29 14:21:18 UTC
Sorry, I totally overlooked it. 
Would you mind following https://fedoraproject.org/wiki/How_to_debug_printing_problems#Filing_a_bug_report and attach requested archive with files - cupsd logs from journal, /etc/cups/cupsd.conf and /etc/cups/printers.conf - after restarting cupsd with debug level debug2?

Comment 4 Andrew Schorr 2018-08-29 19:59:32 UTC
Created attachment 1479567 [details]
debug log

I ran "cupsctl LogLevel=debug2" and then restarted the cups service. I sent a print job and got this status from "lpstat -t":

scheduler is running
system default destination: Epson-XP-830
device for Epson-XP-830: ipp://epson-xp-830/ipp/print
Epson-XP-830 accepting requests since Wed 29 Aug 2018 03:49:35 PM EDT
printer Epson-XP-830 now printing Epson-XP-830-174.  enabled since Wed 29 Aug 2018 03:49:35 PM EDT
        Unable to get printer status.

I saved journalctl output like so: "journalctl -u cups --since 15:48 > /tmp/files/cups.journalctl.txt". I'm also uploading printers.conf and cupsd.conf in the tarball. Is there anything else that you need?

As I said, downgrading to cups-2.2.6-14.fc28.x86_64 fixes the problem. I tried to downgrade to more recent versions, but dnf doesn't seem to have access to 2.2.6-1[567].

Regards,
Andy

Comment 5 Zdenek Dohnal 2018-08-30 07:00:08 UTC
That's awesome, thank you very much!
I'll temporarily remove the patch which caused this issue, so users will print again and I'll need to tweak the patch a little more.
Would you mind checking several things for me:
- when you have cups-2.2.6-18 installed (the newest version), does it help if you add 'SSLOptions MinTLS1.0' into /etc/cups/client.conf and restarting cups?
- do you have anything in your /etc/cups/client.conf? If so, please share it.

I have several reports about this latest cups update, so I would like to know for certain if it is really the same issue, which other people are experiencing, or it is other issue triggered by this update.

Comment 6 Zdenek Dohnal 2018-08-31 11:41:51 UTC
Would you mind trying this scratch build - it is the same package, but previous patch is reverted - so for just to be sure.

https://koji.fedoraproject.org/koji/taskinfo?taskID=29395052

Comment 7 Andrew Schorr 2018-08-31 14:44:45 UTC
My /etc/cups/client.conf was previously empty. I put in "SSLOptions MinTLS1.0", and now it works again. So yes, that fixes the problem.

Also, this doesn't seem to matter, but I see these error messages in journalctl:

Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive JobPrivateAccess on line 122 of /etc/cups/cupsd.conf.
Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive JobPrivateValues on line 123 of /etc/cups/cupsd.conf.
Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive SubscriptionPrivateAccess on line 124 of /etc/cups/cupsd.conf.
Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive SubscriptionPrivateValues on line 125 of /etc/cups/cupsd.conf.

I guess this is logged each time cups restarts.

Comment 8 Andrew Schorr 2018-08-31 14:54:14 UTC
I installed the scratch build, emptied out /etc/cups/client.conf, restarted cups, and printed a job. It works. So the new version looks good.

Thanks,
Andy

Comment 9 Zdenek Dohnal 2018-09-03 10:17:12 UTC
Andy, I'm deeply sorry to bother you, but I'm not able to reproduce the issue properly. Would you mind cooperating with me on testing the fixed package?

I put back the patch which caused the issue, but with a little changes - would you mind testing it?
Just empty out client.conf, restart cups and try to print or issues 'lpstat -t'.

https://koji.fedoraproject.org/koji/taskinfo?taskID=29466738

Comment 10 Andrew Schorr 2018-09-04 02:59:41 UTC
Hi, I installed 2.2.6-20, and it does print without getting the "Unable to get printer status" error.

However: on both 2.2.6-19 and 2.2.6-20, I am having a different problem. After printing a job to my network printer, it never disappears from the queue on my Fedora laptop. It says "Waiting for job to complete.", even though it printed long ago. For example, the test I just printed:

bash$ lpstat -t
scheduler is running
system default destination: Epson-XP-830
device for Epson-XP-830: ipp://epson-xp-830/ipp/print
Epson-XP-830 accepting requests since Mon 03 Sep 2018 10:55:17 PM EDT
printer Epson-XP-830 is idle.  enabled since Mon 03 Sep 2018 10:55:17 PM EDT
        Waiting for job to complete.
Epson-XP-830-180        schorr           15360   Mon 03 Sep 2018 10:54:45 PM EDT

But the printout is already on the printer!

So there seems to be a new bug.

Regards,
Andy

Comment 11 Andrew Schorr 2018-09-04 03:06:40 UTC
And now with 2.2.6-20, I can't even cancel the job:

bash$ lpstat -t
scheduler is running
system default destination: Epson-XP-830
device for Epson-XP-830: ipp://epson-xp-830/ipp/print
Epson-XP-830 accepting requests since Mon 03 Sep 2018 10:55:17 PM EDT
printer Epson-XP-830 is idle.  enabled since Mon 03 Sep 2018 10:55:17 PM EDT
        Waiting for job to complete.
Epson-XP-830-180        schorr           15360   Mon 03 Sep 2018 10:54:45 PM EDT
bash$ cancel 15360
cancel: cancel-job failed: Job #15360 does not exist.
bash$ lpstat -t
scheduler is running
system default destination: Epson-XP-830
device for Epson-XP-830: ipp://epson-xp-830/ipp/print
Epson-XP-830 accepting requests since Mon 03 Sep 2018 10:55:17 PM EDT
printer Epson-XP-830 is idle.  enabled since Mon 03 Sep 2018 10:55:17 PM EDT
        Waiting for job to complete.
Epson-XP-830-180        schorr           15360   Mon 03 Sep 2018 10:54:45 PM EDT

Something is really messed up.

Comment 12 Zdenek Dohnal 2018-09-04 07:24:06 UTC
Andy,

(In reply to Andrew Schorr from comment #11)
> Epson-XP-830-180        schorr           15360   Mon 03 Sep 2018 10:54:45 PM
> EDT
> bash$ cancel 15360
> cancel: cancel-job failed: Job #15360 does not exist.

If you want to cancel job, you need to use:
> Epson-XP-830-180        schorr           15360   Mon 03 Sep 2018 10:54:45 PM
  ----------------
$ cancel Epson-XP-830-180

or:
> Epson-XP-830-180        schorr           15360   Mon 03 Sep 2018 10:54:45 PM
               ---
$ cancel 180

that should work - if it doesn't, please tell me. You used job size for canceling the job.

Other one is clearly a bug, but it doesn't seems to be caused something in -19 or -20, because -19 is just the same as -20 but without the patch. I opened a new bug for it .
Would you mind adding there the necessary files - like files from /etc/cups, cups journald logs and, I think they can be useful in this case, network packet capture when you do printing (by 'tcpdump host <printer_ip> -w network.pcap') - there please?

Comment 13 Zdenek Dohnal 2018-09-04 07:24:31 UTC
Sorry, the link to the bug https://bugzilla.redhat.com/show_bug.cgi?id=1625108 .

Comment 14 Zdenek Dohnal 2018-09-04 08:29:14 UTC
(In reply to Andrew Schorr from comment #7)
> Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive JobPrivateAccess on
> line 122 of /etc/cups/cupsd.conf.
> Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive JobPrivateValues on
> line 123 of /etc/cups/cupsd.conf.
> Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive
> SubscriptionPrivateAccess on line 124 of /etc/cups/cupsd.conf.
> Aug 31 10:33:06 ajs-t530 cupsd[31058]: Unknown directive
> SubscriptionPrivateValues on line 125 of /etc/cups/cupsd.conf.
> 
> I guess this is logged each time cups restarts.

It is caused by last 4 lines from cupsd.conf:

  <Limit All>
    Order deny,allow
  </Limit>
</Policy>
JobPrivateAccess default
JobPrivateValues default
SubscriptionPrivateAccess default
SubscriptionPrivateValues default

These lines should be in some policy tag, as you see in lines 27, 57, 90. I'm not sure which program adds them on the end of cupsd.conf, but you can safely remove form the end of file and you are free of these messages.

Comment 15 Andrew Schorr 2018-09-04 14:34:48 UTC
OK. Sorry about the late night brain fart on the "cancel" command.
I see that you already duplicated the filter error problem that prevents
the job from completing. Do you still want me to provide more info on that one?

Comment 16 Fedora Update System 2018-09-06 11:58:43 UTC
cups-2.2.6-22.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-7b9711d0f6

Comment 17 Fedora Update System 2018-09-07 17:11:13 UTC
cups-2.2.6-22.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-7b9711d0f6

Comment 18 Fedora Update System 2018-09-11 16:54:29 UTC
cups-2.2.6-22.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.