Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

No destination host name supplied by cups-browsed for printer #23

Closed
mgedmin opened this issue Nov 24, 2021 · 25 comments
Closed

No destination host name supplied by cups-browsed for printer #23

mgedmin opened this issue Nov 24, 2021 · 25 comments

Comments

@mgedmin
Copy link

mgedmin commented Nov 24, 2021

Today I cannot print from my Ubuntu 20.10 laptop. The printer is detected, a print job gets created, stays active for 60 seconds, then goes into waiting. /var/log/cups/errorr_log has

E [24/Nov/2021:14:34:36 +0200] [Job 69] Bad value (0) for orientation-requested, using 0 degrees

at the time when the job is first created, then

E [24/Nov/2021:14:35:36 +0200] [Job 69] No destination host name supplied by cups-browsed for printer \"HP_Color_LaserJet_MFP_M477fdw_15A597_\", is cups-browsed running?
W [24/Nov/2021:14:35:36 +0200] [Job 69] Backend returned status 4 (stop printer)

Printing worked fine just a few days ago, with the same Ubuntu version and the same printers. I'm not sure what changed.

OpenPrinting/cups-filters#97 (comment) suggests creating an issue here.

Please check whether at the time of printing cups-browsed is actually running, as cups-browsed tells the job to which destination to go

cups-browsed is running. restarting cups-browsed doesn't make the problem go away.

Which version of cups-filters do you have

1.28.10-2

How many print queues does cups-browsed generate on your system (the ones with implicitclass:/... in the output of lpstat -v).

Two, which is correct: the printer advertises itself over DNS-SD, and there's a local server (fridge.lan) with a CUPS queue for the same printer. Printing to either queue fails in (almost) the same way; the only difference is that only one of the two queues produces the "Bad value (0) for orientation-requested" error.

lpstat -v shows

$ lpstat -v
device for HP_Color_LaserJet_MFP_M477fdw_15A597_: implicitclass://HP_Color_LaserJet_MFP_M477fdw_15A597_/
device for HP_Color_LaserJet_MFP_M477fdw_fridge: implicitclass://HP_Color_LaserJet_MFP_M477fdw_fridge/
device for ML-1640-Series: usb://Samsung/ML-1640%20Series?serial=144QBAAS601512F.

(the USB printer is currently disconnected and is irrelevant to this bug report)

Please create an issue report here with /etc/cups/cupsd.conf and /etc/cups/cups-browsed.conf attached.

(I've made two changes to cups-browsed.conf, compared to stock ubuntu config: removed cups from BrowseLocalProtocols, and uncommented DebugLogging file stderr.)

Also, here's /var/log/cups/cups-browsed_log after I enabled debug logging and restarted cups-browsed, then tried printing.

cups-browsed_log.txt

Other bug reports had questions about Avahi version, so

avahi-resolve --version
avahi-resolve 0.8

I can ping both fridge.local and cream.local, i.e. DNS-SD name resolution works fine on the system. (Besides, cups-browserd detects the printers fine, so it must be seeing mDNS packets).

I'm not sure how to interpret the cups-browsed_log. The "Remote printer overview" section is interesting, particularly where it says things like cream.local, IP not determined. The only things logged during the actual print job execution and failure are printer state change notifications that don't seem to be saying anything.

I wish I had debug logging enabled from when printing worked fine, so I could see what differs between now and then...

@mgedmin
Copy link
Author

mgedmin commented Nov 24, 2021

Got my printout after printing again, then manually running cupsenable HP_Color_LaserJet_MFP_M477fdw_15A597_.

@tillkamppeter
Copy link
Member

Note that cups-browsed skips paused printers when looking for the destination for a job, so if the destination printer of a cups-browsed-generated print queue is paused, cups-browsed does not find a destination and gives the error. So keep an eye that your printers are not paused/disabled when printing.

Also somehow your cups-browsed_log file did not catch the handling of a job.

So should we close this now as you are able to print again?

@mgedmin
Copy link
Author

mgedmin commented Nov 24, 2021

But wasn't the printer originally paused because of this bug?

And doesn't restarting cups-browserd unpause the printer? (I ask because I see the job getting retried and failing again in error_log after I do systemctl restart cups-browsed.service, and don't touch anything else.)

I've experienced the bug once before, in Ubuntu 21.04, with cups-filters 1.28.8. At the time the workaround mentioned in OpenPrinting/cups-filters#321 (restarting cups-browsed) sufficed. This time it didn't.

Also somehow your cups-browsed_log file did not catch the handling of a job.

Yes, that was weird.

I wish I made better notes of what exactly I did; I was sometimes testing by keeping a queued print job and seeing it be retried automatically when I restarted cups-browsed; at other times I deleted the job and printed the file again.

The successful print was after I (1) restarted cups-browsed with debugging enabled, (2) saw an existing print job get retried with no success and scant logging from cups-browsed, (3) deleted the job, (4) printed the file again, then finally (5) ran cupsenable.

The cups-browsed_log attached here was captured after step 2. After step 5 I have a lot of log entries of the successful handling of the job. I could attach the new log, but I'm not sure it's useful.

So should we close this now as you are able to print again?

I don't mind closing the bug, but I have no confidence that it won't come back.

I'm going to keep debug logging enabled so I can provide better logs if this happens again.

@kerneis
Copy link

kerneis commented Nov 29, 2021

I keep hitting a similar bug with Brother network printers on a local network. Printing is extremely unreliable due to it, and I'm not sure what makes it succeed (I generally try to restart cups, cups-browsed and the printer, sometimes to no avail). I'd be happy to provide more information or try debugging things.

See also https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=990331 (I suspected app-armor at some point but I don't think it's the culprit anymore).

@tillkamppeter
Copy link
Member

One additional idea to try (you need to compile C code for that, also mainly for cases where printing sometimes works and sometimes not):

  • First, make sure you have debug logging active as described in the beginning of this thread.
  • in the source file backend/implicitclass.c is a line usleep(500000);. Double the number in this line, compile ( make), copy .libs/implicitclass to /usr/lib/cups/backend (or do make install), try printing again.
  • Is it more reliable now? If not, or not much more reliable, try doubling the number again. If you arrive at a reliable state, tell us the number at which you have arrived.
  • Check the log files for any clues, attach them if in doubt.
  • Tell us also how many printers your cups-browsed is handling (lpstat -v | grep implicitclass: | wc -l).

@mgedmin
Copy link
Author

mgedmin commented Dec 1, 2021

Today I cannot print again. Excerpts from log files in /var/log/cups:

==> access_log <==
localhost - root [01/Dec/2021:10:35:13 +0200] "POST / HTTP/1.1" 200 349 Create-Printer-Subscriptions successful-ok
localhost - root [01/Dec/2021:10:35:17 +0200] "POST /admin/ HTTP/1.1" 200 181 CUPS-Delete-Printer client-error-not-found
localhost - root [01/Dec/2021:10:35:17 +0200] "POST /admin/ HTTP/1.1" 200 14921 CUPS-Add-Modify-Printer successful-ok
localhost - - [01/Dec/2021:10:37:56 +0200] "POST / HTTP/1.1" 200 181 Renew-Subscription client-error-not-found
localhost - - [01/Dec/2021:11:36:16 +0200] "POST / HTTP/1.1" 200 181 Renew-Subscription client-error-not-found
localhost - - [01/Dec/2021:12:34:36 +0200] "POST / HTTP/1.1" 200 181 Renew-Subscription client-error-not-found
localhost - - [01/Dec/2021:13:32:56 +0200] "POST / HTTP/1.1" 200 181 Renew-Subscription client-error-not-found
localhost - - [01/Dec/2021:14:27:02 +0200] "POST /printers/HP_Color_LaserJet_MFP_M477fdw_15A597_ HTTP/1.1" 200 1581876 Print-Job successful-ok
localhost - - [01/Dec/2021:14:31:16 +0200] "POST / HTTP/1.1" 200 181 Renew-Subscription client-error-not-found
localhost - - [01/Dec/2021:14:31:20 +0200] "POST /admin/ HTTP/1.1" 401 180 Resume-Printer successful-ok
localhost - mg [01/Dec/2021:14:31:20 +0200] "POST /admin/ HTTP/1.1" 200 180 Resume-Printer successful-ok

10:35 is when I woke up the laptop in the office network, 14:27 is when I printed a job, 14:31 is when I ran cupsenable HP_Color_LaserJet_MFP_M477fdw_15A597_

==> error_log <==
W [01/Dec/2021:10:35:17 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_fridge-Gray..\' already exists
W [01/Dec/2021:10:35:17 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_fridge-DeviceN..\' already exists
E [01/Dec/2021:14:27:02 +0200] [Job 71] Bad value (0) for orientation-requested, using 0 degrees
E [01/Dec/2021:14:28:02 +0200] [Job 71] No destination host name supplied by cups-browsed for printer \"HP_Color_LaserJet_MFP_M477fdw_15A597_\", is cups-browsed running?
W [01/Dec/2021:14:28:02 +0200] [Job 71] Backend returned status 4 (stop printer)
E [01/Dec/2021:14:31:20 +0200] [Job 71] Bad value (0) for orientation-requested, using 0 degrees
E [01/Dec/2021:14:32:20 +0200] [Job 71] No destination host name supplied by cups-browsed for printer \"HP_Color_LaserJet_MFP_M477fdw_15A597_\", is cups-browsed running?
W [01/Dec/2021:14:32:20 +0200] [Job 71] Backend returned status 4 (stop printer)

Same as last time: a CreateProfile error on printer discovery, a Bad value error whenever a job is being processed, and a No destination host name supplied error from cups-browsed.

Now the interesting bit:
cups-browsed_log.dec1.txt

Printer discovery at 10:35 shows up there. Print jobs at 14:27 or 14:31, however, do not. The only thing that appears are those repeated

nm_properties_changed() in THREAD 139756731443904

messages.

Does this provide any clues to anyone?

I'm also attaching the logrotated cups-browsed_log.1, just in case there might be clues how cups-browsed got into this situation where it ignores jobs:
cups-browsed_log.nov29-30.txt

cups-browsed_log.2.gz ends with

Mon Nov 29 12:28:38 2021 NetworkManager ActiveConnections changed
Mon Nov 29 12:28:38 2021 Caught signal 15, shutting down ...
Mon Nov 29 12:28:38 2021 main loop exited
Mon Nov 29 12:28:38 2021 Processing printer list ...
Mon Nov 29 12:28:38 2021 === Remote printer overview ===
Mon Nov 29 12:28:38 2021 ===============================
Mon Nov 29 12:28:38 2021 === Remote printer overview ===
Mon Nov 29 12:28:38 2021 ===============================
Mon Nov 29 12:28:38 2021 Error subscribing to CUPS notifications: Subscription #1751 does not exist.
Mon Nov 29 12:28:38 2021 cups-browsed [BrowsePoll /run/cups/cups.sock:0]: IPP-Cancel-Subscription
Mon Nov 29 12:28:38 2021 cupsd-browsed [BrowsePoll /run/cups/cups.sock:0]: failed: Subscription #1750 does not exist.
Mon Nov 29 12:28:38 2021 free_local_printer() in THREAD 140102439914176

so I think older logrotated files aren't relevant.

@mgedmin
Copy link
Author

mgedmin commented Dec 1, 2021

Since I had to print, I did a sudo systemctl restart cups-browsed.log, a bunch of cupsenables that didn't do anything, one cupsdisable + cupsenable pair ditto, and then I figured out the job itself was paused and so I found the GUI button to resume it. Twice (1st failed with the same error, 2nd worked fine).

Additional logs:

==> access_log <==
localhost - root [01/Dec/2021:14:46:09 +0200] "POST /admin/ HTTP/1.1" 200 223 Pause-Printer successful-ok
localhost - root [01/Dec/2021:14:46:09 +0200] "POST /admin/ HTTP/1.1" 200 181 CUPS-Delete-Printer successful-ok
localhost - root [01/Dec/2021:14:46:09 +0200] "POST / HTTP/1.1" 200 123 Cancel-Subscription client-error-not-found
localhost - - [01/Dec/2021:14:46:09 +0200] "POST / HTTP/1.1" 200 152 Cancel-Subscription successful-ok
localhost - - [01/Dec/2021:14:46:09 +0200] "POST / HTTP/1.1" 200 349 Create-Printer-Subscriptions successful-ok
localhost - - [01/Dec/2021:14:46:09 +0200] "POST / HTTP/1.1" 200 176 Create-Printer-Subscriptions successful-ok
localhost - - [01/Dec/2021:14:46:11 +0200] "POST /admin/ HTTP/1.1" 401 180 Resume-Printer successful-ok
localhost - mg [01/Dec/2021:14:46:11 +0200] "POST /admin/ HTTP/1.1" 200 180 Resume-Printer successful-ok
localhost - - [01/Dec/2021:14:46:13 +0200] "POST /admin/ HTTP/1.1" 401 239 CUPS-Add-Modify-Printer successful-ok
localhost - root [01/Dec/2021:14:46:13 +0200] "POST /admin/ HTTP/1.1" 200 239 CUPS-Add-Modify-Printer successful-ok
localhost - root [01/Dec/2021:14:46:13 +0200] "POST /admin/ HTTP/1.1" 200 232 CUPS-Add-Modify-Printer successful-ok
localhost - root [01/Dec/2021:14:46:13 +0200] "POST /admin/ HTTP/1.1" 200 232 CUPS-Add-Modify-Printer successful-ok
localhost - root [01/Dec/2021:14:46:16 +0200] "POST /admin/ HTTP/1.1" 200 15996 CUPS-Add-Modify-Printer successful-ok
localhost - root [01/Dec/2021:14:46:16 +0200] "POST /admin/ HTTP/1.1" 200 206 CUPS-Add-Modify-Printer successful-ok
localhost - root [01/Dec/2021:14:46:16 +0200] "POST /admin/ HTTP/1.1" 200 181 CUPS-Delete-Printer client-error-not-found
localhost - root [01/Dec/2021:14:46:16 +0200] "POST /admin/ HTTP/1.1" 200 14921 CUPS-Add-Modify-Printer successful-ok
localhost - - [01/Dec/2021:14:47:08 +0200] "POST /admin/ HTTP/1.1" 401 180 Resume-Printer successful-ok
localhost - mg [01/Dec/2021:14:47:08 +0200] "POST /admin/ HTTP/1.1" 200 180 Resume-Printer successful-ok
localhost - - [01/Dec/2021:14:47:15 +0200] "POST /admin/ HTTP/1.1" 401 180 Pause-Printer successful-ok
localhost - mg [01/Dec/2021:14:47:15 +0200] "POST /admin/ HTTP/1.1" 200 180 Pause-Printer successful-ok
localhost - - [01/Dec/2021:14:47:17 +0200] "POST /admin/ HTTP/1.1" 401 180 Resume-Printer successful-ok
localhost - mg [01/Dec/2021:14:47:17 +0200] "POST /admin/ HTTP/1.1" 200 180 Resume-Printer successful-ok
localhost - - [01/Dec/2021:14:47:29 +0200] "POST / HTTP/1.1" 200 342 Create-Printer-Subscriptions successful-ok
localhost - - [01/Dec/2021:14:47:29 +0200] "POST / HTTP/1.1" 200 5236835 CUPS-Get-PPDs -
localhost - - [01/Dec/2021:14:47:38 +0200] "POST /jobs/ HTTP/1.1" 200 164 Set-Job-Attributes successful-ok
localhost - root [01/Dec/2021:14:47:39 +0200] "POST /admin/ HTTP/1.1" 200 310 CUPS-Add-Modify-Printer successful-ok
localhost - - [01/Dec/2021:14:48:05 +0200] "POST /jobs/ HTTP/1.1" 200 164 Set-Job-Attributes successful-ok
localhost - root [01/Dec/2021:14:48:07 +0200] "POST /admin/ HTTP/1.1" 200 310 CUPS-Add-Modify-Printer successful-ok
localhost - - [01/Dec/2021:14:49:02 +0200] "POST / HTTP/1.1" 200 150 Cancel-Subscription successful-ok
localhost - - [01/Dec/2021:14:49:02 +0200] "POST / HTTP/1.1" 200 150 Cancel-Subscription client-error-not-found
==> error_log <==
E [01/Dec/2021:14:46:11 +0200] [Job 71] Bad value (0) for orientation-requested, using 0 degrees
E [01/Dec/2021:14:46:13 +0200] [Job 71] No suitable destination host found by cups-browsed.
W [01/Dec/2021:14:46:13 +0200] [Job 71] Backend returned status 6 (retry job later)
W [01/Dec/2021:14:46:16 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_15A597_-Gray..\' already exists
W [01/Dec/2021:14:46:16 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_15A597_-DeviceN..\' already exists
W [01/Dec/2021:14:46:16 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_fridge-Gray..\' already exists
W [01/Dec/2021:14:46:16 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_fridge-DeviceN..\' already exists
E [01/Dec/2021:14:47:38 +0200] [Job 71] No suitable destination host found by cups-browsed.
E [01/Dec/2021:14:47:38 +0200] [Job 71] Bad value (0) for orientation-requested, using 0 degrees
W [01/Dec/2021:14:47:38 +0200] [Job 71] Backend returned status 6 (retry job later)
E [01/Dec/2021:14:48:05 +0200] [Job 71] Bad value (0) for orientation-requested, using 0 degrees

cups-browsed_log is too big for excerpts, so here's a full version:
cups-browsed_log.dec1.success.txt

Curiously I see that it ends with the same

Mon Nov 29 12:28:38 2021 Caught signal 15, shutting down ...
Mon Nov 29 12:28:38 2021 main loop exited
Mon Nov 29 12:28:38 2021 Processing printer list ...
Mon Nov 29 12:28:38 2021 === Remote printer overview ===
Mon Nov 29 12:28:38 2021 ===============================
Mon Nov 29 12:28:38 2021 === Remote printer overview ===
Mon Nov 29 12:28:38 2021 ===============================
Mon Nov 29 12:28:38 2021 Error subscribing to CUPS notifications: Subscription #1751 does not exist.
Mon Nov 29 12:28:38 2021 cups-browsed [BrowsePoll /run/cups/cups.sock:0]: IPP-Cancel-Subscription
Mon Nov 29 12:28:38 2021 cupsd-browsed [BrowsePoll /run/cups/cups.sock:0]: failed: Subscription #1750 does not exist.
Mon Nov 29 12:28:38 2021 free_local_printer() in THREAD 140102439914176

bit that I earlier assumed the service was shutting down, what with the "shutting down ..." and "main loop exited", but ps shows that the process is still running:

$ ps -o pid,lstart,etime,cmd $(pgrep cups-browsed)
    PID                  STARTED     ELAPSED CMD
1934848 Wed Dec  1 14:46:09 2021       06:47 /usr/sbin/cups-browsed

Could this be a clue? main loop exits, so cups-browsed stops responding to hostname and whatnot queries issued by cupsd? Some other threads keep the cups-browsed process itself alive, so systemd doesn't restart it.

I just printed a test page and it came out fine, so no, that's a red herring.

@tillkamppeter
Copy link
Member

@mgedmin Could it be that you had 2 cups-browsed processes running? The log output of the shutdown sequence would be then from one and the process you have seen afterwards from the other. And while there were two cups-browsed processes running, competing somehow with each other you were not able to print and as soon as one got shut down you could print, controlled by the other.

So check whether there is more than one cups-browsed running if you cannot print again.

Do a sudo killall cups-browsed to terminate all cups-browsed processes. If your system uses systemd then systemd will start one single cups-browsed (watch dog/automatic crash recovery). Now printing should work again.

@mgedmin
Copy link
Author

mgedmin commented Dec 8, 2021

I have the atop daemon running in the background, which records system snapshots (such as PIDs and command lines) every 10 minutes. Looking at the log file for Nov 29 and Nov 30, I see that only one cups-browsed process is running at one time, but the PID changes after each main loop exited message. By some coincidence atop's own log files are rotated at the exact same time, so I think this is anacron running daily jobs on my laptop.

Looking at these cups-browsed restart timestamps, I think I got mixed up between terminal tabs and log files in my earlier comment -- there was no restart on Dec 1:

mg@blynas: /var/log/cups $ zgrep 'main loop exi' cups-browsed_log*
cups-browsed_log.1:Wed Dec  8 12:32:22 2021 main loop exited
cups-browsed_log.2.gz:Tue Dec  7 13:57:52 2021 main loop exited
cups-browsed_log.3.gz:Mon Dec  6 15:23:41 2021 main loop exited
cups-browsed_log.4.gz:Sat Dec  4 10:54:54 2021 main loop exited
cups-browsed_log.5.gz:Tue Nov 30 10:23:10 2021 main loop exited
cups-browsed_log.6.gz:Mon Nov 29 12:28:38 2021 main loop exited
cups-browsed_log.7.gz:Sat Nov 27 07:33:47 2021 main loop exited
cups-browsed_log.7.gz:Sun Nov 28 10:22:12 2021 main loop exited

@makuser
Copy link

makuser commented Jan 5, 2022

There are two different issues for the same bug, OpenPrinting/cups-filters#357 and #23. What is the difference between them, because I have not been able to find one. Maybe one should be closed and marked as duplicate of the other.

I am running into the same issue on several machines running Ubuntu 20.04, I might be able to help out if any more information is needed. Is that the case, is there something to test out?

@TinyTrebuchet
Copy link

@mgedmin Could you please enable CUPS debugging and attach all the log files here again after an unsuccessful print job?

To enable CUPS debugging, run:

cupsctl --debug-logging

and then restart CUPS.

@TinyTrebuchet
Copy link

@makuser If you are running into the same issue, could you attach your CUPS error_log and cups-browsed_log (with debugging enabled) here after handling an unsuccessful print job? Enable CUPS debugging as shown above. cups-browsed debugging can be enabled by editing /etc/cups/cups-browsed.conf and adding this line:

DebugLogging file

and then restarting cups-browsed.

@tillkamppeter
Copy link
Member

Perhaps the problem is caused by AppArmor settings.

See:

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=990331

So look for messages containing audit in the syslog.

@mgedmin
Copy link
Author

mgedmin commented Feb 23, 2022

Is there a way of testing whether cupsd can talk to cups-browsed and get a valid IP, without wasting paper? I've been delaying additional testing on this issue because I don't have anything I want to print (and I irrationally believe that printing would work if the only reason I did it was to reproduce a bug).

The apparmor allegations have been mentioned before, in an earlier comment, and don't quite explain why the bug would be non-deterministic and go away after restarting/unpausing/retrying things without adjusting AppArmor profiles or enforcement rules...

@brunetton
Copy link

Kind of same issues here. Network HP Laserjet 1028 printer (behind a Raspberry Pi Zero); printer is often listed as disabled in system-config-printer.py, and the same "No destination host name supplied by cups-browsed for printer" message.

It works sometimes; seems random to me (tried to identify some correlation with reboots but without success). To print I use my Android phone, it works perfectly from the phone.

I'm aware this comment is no very helpful as it, but maybe can I give more information as it seems related to this bug.

Ubuntu 22.04 LTS

@MkTr
Copy link

MkTr commented Feb 8, 2023

Hi, I went through a similar problem recently and fixed it. After an update (I'm assuming ubuntu was updated to 22.04.1, but I wasn't there - someone else updated it), my ubuntu briefly worked with my printer before stopping, and after attempting to set it up again (with the message there was an error during the cups operation "server-error-internal-error") it didn't even acknowledge that the printer existed. Somehow someone else was able to connect it, but every test print was stopped with the "no destination" error.
I temporarily solved the problem by following a cups setup tutorial: opened /etc/cups/cupsd.conf in a text editor, went to the <Location /admin> section, and replaced it with the following.

<Location /admin>
  AuthType Default
  Require valid-user
  Order allow,deny
  Allow @LOCAL
</Location>

In the cupsd.conf file you uploaded, your /admin section looks like this - I think it's what mine looked like before I changed it:

<Location /admin>
  Order allow,deny
</Location>

The printer soon stopped working again (at one point, it stopped working with non-linux computers and had to be reconnected to our router) - this time with the error "cups-pki-invalid", which people found and solved here: https://bugs.launchpad.net/ubuntu/+source/cups/+bug/1973441

For steps on how to delete the outdated certificate:
1)Figure out how to open your file manager with root permissions, and navigate to /etc/cups/ssl. For me, I had to open the terminal and use the command
sudo xdg-open /etc/cups/ssl/
But it might be different for you if you use nautilus (the nautilus command doesn't work on my computer).
2)In the ssl folder, find a file with your printer's name, ending with ".local.crt", and delete it. Even with root permissions, file explorer didn't allow me to delete protected files, so I had to use the terminal:
sudo rm /etc/cups/ssl/YOURPRINTERNAMEHERE.local.crt
3)Restart cups for the sake of it with "sudo systemctl restart cups", connect your printer to the computer if it isn't, and try printing.

After all of this, my printer started working again without issues. I don't know that much about linux - I won't be able to help you further if this doesn't work for you or if you run into any problems. But I don't believe any of these instructions will harm your computer, and hopefully you at least get closer to diagnosing the problem.

@brunetton
Copy link

brunetton commented Feb 10, 2023

Thanks for sharing @MkTr !

I just tried this solution:

  • edit /etc/cups/ssl/
  • remove certificate

=> it didn't changed anything in my case :(

BUT after deleting and re-adding printer in /usr/share/system-config-printer/system-config-printer.py utility, it works again 👍 🎉

No idea if the previous steps (that you proposed) helped or not but I assume it does (I'm quite sure I already tried to delete and recreate shared printer).

Note: all modifications have been made on the computer that sends data to printer, not my Raspberry Pi that runs CUPS server and is physically plugged to the printer.

Thanks !

@jojoax
Copy link

jojoax commented Mar 1, 2023

This ugly bug fucks up here every few days.
DNSSD is simply not working,k it braeks plenty thing.

Return to working Browsing methods fom cups 1.0, befor Apple bought cups and broke/destroyed the fantastic working linux network printing.
FUCK Apple!

@pnunn
Copy link

pnunn commented Apr 29, 2023

I'm having this issue with two kde Neon computers. My Epson WF 7620 has worked fine for years, but a recent update caused these issues and I'm only now getting to try and work it out.

No matter what I try (removing cups-browsed, re-adding it, stopping and starting it) I cannot get a test page to print, the printer always goes into pause, and when I restart it with the gui or command line, I get an extra page, but still no print.

The log file looks like
W [29/Apr/2023:18:03:30 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:03:30 +1000] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
E [29/Apr/2023:18:05:08 +1000] [Job 117] No destination host name supplied by cups-browsed for printer "EPSON_WF_7620_Series", is cups-browsed running?
W [29/Apr/2023:18:05:08 +1000] [Job 117] Backend returned status 4 (stop printer)
E [29/Apr/2023:18:06:27 +1000] [Job 117] No destination host name supplied by cups-browsed for printer "EPSON_WF_7620_Series", is cups-browsed running?
W [29/Apr/2023:18:06:27 +1000] [Job 117] Backend returned status 4 (stop printer)
W [29/Apr/2023:18:06:33 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] Printer drivers are deprecated and will stop working in a future version of CUPS. See https://github.com/OpenPrinting/cups/issues/103
E [29/Apr/2023:18:06:33 +1000] [Job 114] Files have gone away.
W [29/Apr/2023:18:06:33 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:33 +1000] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:38 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:38 +1000] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [29/Apr/2023:18:06:38 +1000] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
E [29/Apr/2023:18:07:43 +1000] [Job 117] No destination host name supplied by cups-browsed for printer "EPSON_WF_7620_Series", is cups-browsed running?
W [29/Apr/2023:18:07:43 +1000] [Job 117] Backend returned status 4 (stop printer)

when I've done a bunch of systemctl restart cups-browsed, systemctl restart cups, or cupsenable EPSON_WF_7620_Series.

Just for good testing I tried sudo cupsenable EPSON_WF_7620_Series, but that seems to have made things worse, the log having

E [29/Apr/2023:18:14:19 +1000] [Client 4] Returning IPP client-error-bad-request for Create-Printer-Subscriptions (/) from localhost.
E [29/Apr/2023:18:15:04 +1000] [Client 2] Returning IPP client-error-not-possible for Cancel-Job (ipp://pnunn@localhost:631/printers/EPSON_WF_7620_Series) from localhost.
E [29/Apr/2023:18:16:28 +1000] [Job 118] No destination host name supplied by cups-browsed for printer "EPSON_WF_7620_Series", is cups-browsed running?
W [29/Apr/2023:18:16:28 +1000] [Job 118] Backend returned status 4 (stop printer)

and it still died.

Any other thoughts?

@gmejzej
Copy link

gmejzej commented May 17, 2023

I have this problem on Debian 11 with GNOME desktop environment. Trying to print from an HP LaserJet Pro MFP printer.

@Quiigi
Copy link

Quiigi commented Jun 22, 2023

Same issue (fixed for now, see below) on Ubuntu 22.04.2 LTS; one minute after trying to print, I get:

E [21/Jun/2023:17:34:32 -0400] [Job 79] No destination host name supplied by cups-browsed for printer \"Brother_MFC_J4710DW\", is cups-browsed running?
W [21/Jun/2023:17:34:32 -0400] [Job 79] Backend returned status 4 (stop printer)

Initially the printer was found automagically, and just worked, but not robustly. As others noted, it's a bit random. Every midnight, CUPS seems to roll the dice; if I'm lucky I can print that day, if I'm unlucky I cannot. (The timestamp of /etc/cups/printers.conf is always the day's midnight.) From /var/log/cups/cups-browsed_log I see that the daemon is running, and finds the printer. Recently I noticed some odd lines:

Wed Jun 21 00:00:09 2023 Queue name Brother_MFC_J4710DW already taken.
Wed Jun 21 00:00:09 2023 Using fallback queue name: Brother_MFC_J4710DW@brotherher5E309.local

The CUPS filters readme https://github.com/jianglei12138/cups-filters/blob/master/README provides "some info on how cups-browsed works internally", a lot of helpful documentation, in particular:

    Do not overwrite existing queues which are not created by us If
    the simple <remote_printer> name is already taken, try to create a
    <remote_printer>@<server> name, if this is also taken, ignore the
    remote printer. Do not retry, to avoid polling CUPS all the time.
    Queue identified as from this daemon by doing the equivalent of
    "lpadmin -p printer -o cups-browsed-default", this generates a
    "cups-browsed" attribute in printers.conf with value "true".

Sure enough my printer Brother_MFC_J4710DW lacks the cups-browsed attribute, even though it was originally created by cups-browsed. That it was lost could be considered a bug. (There have been several reboots since the creation.) The lpadmin command line given in the README may have a typo because it does nothing. But the following worked for me:

lpadmin -p Brother_MFC_J4710DW -o cups-browsed=true
cupsenable Brother_MFC_J4710DW
sudo systemctl restart cups-browsed

The first command wrote a new /etc/cups/printers.conf with a cups-browsed line. I'm not sure if cupsenable was necessary, but it was definitely not sufficient. After restarting cups-browsed, the job that was still in my queue printer successfully.

@mgedmin
Copy link
Author

mgedmin commented Sep 26, 2023

Tried to print a page today after a looong break, got the

No destination host name supplied by cups-browsed for printer "HP_Color_LaserJet_MFP_M477fdw_15A597", is cups-browsed running?

error again. Ubuntu 23.04, cups 2.4.2-3ubuntu2.5, cups-browsed 2.0~rc1-0ubuntu1.1.

Tried restarting cups-browsed, tried pausing/unpausing the job in gnome-control-center, tried deleting the job and printing again through a different printer (same device, different queue that goes through our office's local server running CUPS exporting the print queues), the page got printed. No time for deep debugging again. I do have some kind of debug logging enabled in cups-browsed.conf from previous attempts, the relevant time range seems to be

Tue Sep 26 14:13:05 2023 140281108376320 nm_properties_changed() in THREAD 140281108376320
Tue Sep 26 16:14:34 2023 140281108376320 on_printer_state_changed() in THREAD 140281108376320
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Printer state change on printer HP_Color_LaserJet_MFP_M477fdw_15A597: Printer "HP_Color_LaserJet_MFP_M477fdw_15A597" state changed to processing.
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Printer state reasons: none
Tue Sep 26 16:14:34 2023 140281108376320 on_job_state() in THREAD 140281108376320
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Job state changed on printer HP_Color_LaserJet_MFP_M477fdw_15A597: Job OpenPrinting/cups-filters#92 started.
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Printer state reasons: none
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Job ID: 92
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Job State: job-printing
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Job is processing: Yes
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] HP_Color_LaserJet_MFP_M477fdw_15A597 starts processing a job.
Tue Sep 26 16:14:34 2023 140281108376320 on_printer_state_changed() in THREAD 140281108376320
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Printer state change on printer HP_Color_LaserJet_MFP_M477fdw_15A597: Printer "HP_Color_LaserJet_MFP_M477fdw_15A597" state changed.
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Printer state reasons: none
Tue Sep 26 16:14:34 2023 140281108376320 on_printer_state_changed() in THREAD 140281108376320
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Printer state change on printer HP_Color_LaserJet_MFP_M477fdw_15A597: Printer "HP_Color_LaserJet_MFP_M477fdw_15A597" state changed.
Tue Sep 26 16:14:34 2023 140281108376320 [CUPS Notification] Printer state reasons: none
Tue Sep 26 16:15:35 2023 140281108376320 on_printer_state_changed() in THREAD 140281108376320
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Printer state change on printer HP_Color_LaserJet_MFP_M477fdw_15A597: Printer "HP_Color_LaserJet_MFP_M477fdw_15A597" state changed.
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Printer state reasons: none
Tue Sep 26 16:15:35 2023 140281108376320 on_printer_state_changed() in THREAD 140281108376320
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Printer state change on printer HP_Color_LaserJet_MFP_M477fdw_15A597: Printer "HP_Color_LaserJet_MFP_M477fdw_15A597" state changed.
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Printer state reasons: none
Tue Sep 26 16:15:35 2023 140281108376320 on_job_state() in THREAD 140281108376320
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Job state changed on printer HP_Color_LaserJet_MFP_M477fdw_15A597: Printer stopped due to backend errors; please consult the /var/log/cups/error_log file for details.
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Printer state reasons: none
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Job ID: 92
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Job State: none
Tue Sep 26 16:15:35 2023 140281108376320 [CUPS Notification] Job is processing: No

after which I restarted cups-browsed.

Full cups-browsed_log: cups-browsed_log.txt

error_log has

W [26/Sep/2023:10:12:21 +0300] Printer drivers are deprecated and will stop working in a future version of CUPS. See https://github.com/OpenPrinting/cups/issues/103
E [26/Sep/2023:10:12:26 +0300] [Client 5] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:10:12:28 +0300] [Client 14] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:10:12:33 +0300] [Client 21] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
W [26/Sep/2023:10:12:42 +0300] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_fridge-Gray..\' already exists
W [26/Sep/2023:10:12:42 +0300] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_fridge-DeviceN..\' already exists
W [26/Sep/2023:10:12:43 +0300] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_15A597@cream.local-Gray..\' already exists
W [26/Sep/2023:10:12:43 +0300] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'HP_Color_LaserJet_MFP_M477fdw_15A597@cream.local-DeviceN..\' already exists
E [26/Sep/2023:10:12:43 +0300] [Client 29] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:10:12:43 +0300] [Client 30] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:16:13:54 +0300] [Client 39] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:16:14:35 +0300] [Client 51] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:16:14:35 +0300] [Client 52] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:16:15:35 +0300] [Job 92] No destination host name supplied by cups-browsed for printer \"HP_Color_LaserJet_MFP_M477fdw_15A597\", is cups-browsed running?
W [26/Sep/2023:16:15:35 +0300] [Job 92] Backend returned status 4 (stop printer)
E [26/Sep/2023:16:15:35 +0300] [Client 56] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.
E [26/Sep/2023:16:15:36 +0300] [Client 57] Returning IPP client-error-not-possible for CUPS-Create-Local-Printer (ipp://localhost/) from localhost.

@brunoooooooooooooo
Copy link

brunoooooooooooooo commented Sep 26, 2023

Just wanted to chime in here, I'm experiencing the same on Debian 12. The bug seems to have been around for an absurdly long time (threads about it on StackOverflow from 2019!) and affects quite a good chunk of people. I personally solved it by just removing cups-browsed from my system completely, although it isn't exactly the nicest solution if you actually need it :P

PS not caused by apparmor for me and appears to have been solved in OpenPrinting/cups-filters#148 but still nothing

@marcinpraczko
Copy link

I have say that I had the same issue on Kubuntu (Ubuntu 23.10). Initially I was really happy - printer was auto-detected, and after day or two I started to have the same error. I didn't have time to investigate so I ended with removing cups-browsed and things started working as expected. Printer added and is printing. So not sure what is wrong but error is really making people frustrated especially when some quick print needs be done and .... it can't be done because of this error.

@tillkamppeter tillkamppeter transferred this issue from OpenPrinting/cups-filters Dec 6, 2023
@tillkamppeter
Copy link
Member

I have found a solution for this, please try it out, current GIT master of cups-browsed (2.x, not cups-filters): 57d9351

As queues with implicitclass://... device URI are always created by cups-browsed and do not work without cups-browsed I let cups-browsed consider these always as created by cups-browsed, regardless of whether they have the cups-browsed=true attribute.

I have also changed the behavior when a queue created by cups-browsed gets externally overwritten. Such queues only get released by cups-browsed and replaced by a differently named queue if the implicitclass://... device URI is replaced by something else. If the device URI stays intact and only the PPD is modified, we recover the original PPD and keep the queue.

This way we will never have implicitclass://... queues without supervision by cups-browsed ...

So please test ...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests