Ubuntu
cups-browsed package

cups-browsed is using an excessive amount of CPU

Bug #2018504 reported by James Henstridge
222
This bug affects 49 people
Affects Status Importance Assigned to Milestone
cups-browsed (Ubuntu)
Fix Released
High
Unassigned
Lunar
Fix Released
High
Unassigned

Bug Description

[ Impact ]

One observes that a certain time after booting cups-browsed suddenly starts to occupy a certain percentage or all of one CPU core. This slows down other processes on the system, consumes battery power, causes noise of the CPU fan.

It does not require to have any local printers set up on ones machine, but there must be printers available in the local network.

A typical trigger for this bug is a sudden disappearing of a printer in the network, for example if a laptop shares a printer and it gets suspended by closing the lid. This way the shared printer most probably disappears without the laptop's Avahi sending out some "disappered" notification.

cups-browsed does not recover from the failure, once failed it consumes CPU and stops working, until being restarted, for most with the next boot.

The problem got introduced on the transition from cups-browsed 1.x to 2.x (in Ubuntu 23.04). cups-browsed got a multi-threading feature added to be able to create more local queues at a time, especially when there are many printers available in the network..

The bug is in the error handling: If cups-browsed fails to access a remote printer in a sub-thread, it sets a flag to inform the main thread, to stop an update loop. The main thread misses to reset the flag once it has stopped the loop and so any further update loop during the rest of the life of cups-browsed gets stopped immediately, no printers updated at all, and as because of the updates not performed, updates are still needed and so the loop called again immediately, ending up in an infinite busy loop.

And these access errors happen especially if a remote printer goes away without any DNS-SD/Avahi notification about it disappearing.

So not only CPU load is caused but cups-browsed ceases completely to work.

[ Test Plan ]

This bug is not easy to reproduce, but at least for everyone who reported it here it occurs again and again. So everyone already suffering it is asked to test the proposed SRU package.

To try to reproduce it one ideally takes 2 computers, one running Ubuntu 23.04 with the affected cups-browsed (the client) and one running any Linux and sharing printers by means of CUPS queues, Printer Applications, or the ippeveprinter utility (the server).

Some ways to try to trigger the failure on the client:

- Suspend the server, either by closing its laptpp lid or by selecting the
  "Suspend" function in its desktop's menus.

- On the server start a Printer Application or ippeveprinter manually (this way
  no systemd watch dog applies to it). Then hard-kill its process with "kill -9
  ...".

- If the server is connected to the local network only by wired Ethernet, unplug
  its Ethernet cable.

- If the server is connected to the local network only by Wi-Fi, switch it into
  flight mode.

All these methods should make (a) shared printer(s) on the server go away without getting it properly de-registered from Avahi on the server, and so no notification being broadcasted into the local network. So the client's cups-browsed would not remove the corresponding local print queue and keep maintaining it, sooner or later failing to access the printer and then getting stuck as described above.

Anyone who is suffering this bug could also simply install the proposed package and observe and when the CPU load by cups-browsed does not appear again after some days consider the fix as verified.

[ Where problems could occur ]

The fix does nothing more than removing the mentioned flag, and instead mark the remote printer as disappeared. This way the update loop is not stopped but finishes normally, which is no problem as the remote printers are independent, there is no reason to skip updating printers because one printer failed.

After the update loop having completed, in the next update loop the local queue for the faulty printer gets removed, as it is marked as disappeared.

If cups-browsed gets notified about a disappeared printer by Avahi, it also marks it as disappeared so that the queue gets removed in the next update loop. So now we do the same with faulty printers, which simply do not answer to an IPP request.

As the regular procedure when a remote printer gets shut down works correctly we do not actually expect regressions here.

[ Original Description ]

It could be a problem with the network, but I'm seeing cups-browsed appearing to keep one CPU core busy. According to systemctl, it has used 51 minutes of CPU time since being started 6 hours ago (the laptop has been suspended a few times in that time):

     Active: active (running) since Thu 2023-05-04 08:41:36 CEST; 6h ago
   Main PID: 68281 (cups-browsed)
      Tasks: 4 (limit: 18785)
     Memory: 7.0M
        CPU: 51min 32.735s

This seems surprising, since I'd only expect it to be doing something when printers are advertised over mDNS.

It may be unrelated, but I'm also seeing warnings like the following in the journal:

    May 04 14:26:11 lrrr cups-browsed[68281]: Source ID 1207266864 was not found when attempting to remove it
    May 04 14:26:11 lrrr cups-browsed[68281]: Source ID 1207318247 was not found when attempting to remove it
    May 04 14:26:11 lrrr cups-browsed[68281]: Source ID 1207362184 was not found when attempting to remove it
    May 04 14:26:11 lrrr cups-browsed[68281]: Source ID 1207375185 was not found when attempting to remove it
    May 04 14:38:28 lrrr cups-browsed[68281]: Source ID 1303173242 was not found when attempting to remove it
    May 04 14:38:28 lrrr cups-browsed[68281]: Source ID 1303188526 was not found when attempting to remove it
    May 04 14:38:28 lrrr cups-browsed[68281]: Source ID 1303229832 was not found when attempting to remove it
    May 04 14:38:28 lrrr cups-browsed[68281]: Source ID 1303249965 was not found when attempting to remove it
    May 04 14:38:28 lrrr cups-browsed[68281]: Source ID 1303265399 was not found when attempting to remove it
    May 04 14:38:39 lrrr cups-browsed[68281]: Source ID 1304615115 was not found when attempting to remove it
    May 04 14:50:48 lrrr cups-browsed[68281]: Source ID 1398290009 was not found when attempting to remove it
    May 04 14:50:48 lrrr cups-browsed[68281]: Source ID 1398304338 was not found when attempting to remove it
    May 04 14:50:48 lrrr cups-browsed[68281]: Source ID 1398387203 was not found when attempting to remove it
    May 04 14:50:51 lrrr cups-browsed[68281]: Source ID 1398664816 was not found when attempting to remove it
    May 04 14:50:51 lrrr cups-browsed[68281]: Source ID 1398674240 was not found when attempting to remove it
    May 04 14:50:51 lrrr cups-browsed[68281]: Source ID 1398687187 was not found when attempting to remove it
    May 04 14:50:51 lrrr cups-browsed[68281]: Source ID 1398698982 was not found when attempting to remove it
    May 04 14:50:51 lrrr cups-browsed[68281]: Source ID 1398726803 was not found when attempting to remove it
    May 04 14:52:24 lrrr cups-browsed[68281]: Source ID 1410715532 was not found when attempting to remove it
    May 04 14:52:24 lrrr cups-browsed[68281]: Source ID 1410741036 was not found when attempting to remove it
    May 04 14:52:24 lrrr cups-browsed[68281]: Source ID 1410777106 was not found when attempting to remove it
    May 04 14:52:25 lrrr cups-browsed[68281]: Source ID 1410797157 was not found when attempting to remove it

These errors seem to be generated when glib's g_source_remove() function is called with an ID for a job that doesn't exist. This could indicate that cups-browsed is losing track of an idle or timeout function.

ProblemType: Bug
DistroRelease: Ubuntu 23.04
Package: cups-browsed 2.0~rc1-0ubuntu1
ProcVersionSignature: Ubuntu 6.2.0-20.20-generic 6.2.6
Uname: Linux 6.2.0-20-generic x86_64
ApportVersion: 2.26.1-0ubuntu2
Architecture: amd64
CasperMD5CheckResult: unknown
CurrentDesktop: ubuntu:GNOME
Date: Thu May 4 15:10:03 2023
InstallationDate: Installed on 2017-09-02 (2070 days ago)
InstallationMedia: Ubuntu 17.10 "Artful Aardvark" - Alpha amd64 (20170901)
MachineType: LENOVO 20HRCTO1WW
Papersize: a4
PpdFiles:
 Error: command ['fgrep', '-H', '*NickName', '/etc/cups/ppd/Lexmark_MS610dn_3_.ppd', '/etc/cups/ppd/test6_59CD60.ppd', '/etc/cups/ppd/HP_OfficeJet_Pro_8710_C7327F.ppd', '/etc/cups/ppd/test4_F7866E.ppd', '/etc/cups/ppd/HP_Smart_Tank_530_series_E23C83.ppd'] failed with exit code 2: grep: /etc/cups/ppd/Lexmark_MS610dn_3_.ppd: Permission denied
 grep: /etc/cups/ppd/test6_59CD60.ppd: Permission denied
 grep: /etc/cups/ppd/HP_OfficeJet_Pro_8710_C7327F.ppd: Permission denied
 grep: /etc/cups/ppd/test4_F7866E.ppd: Permission denied
 grep: /etc/cups/ppd/HP_Smart_Tank_530_series_E23C83.ppd: Permission denied
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-6.2.0-20-generic root=UUID=94446fd9-8625-46ee-a8de-034cc22d680b ro quiet splash vt.handoff=7
SourcePackage: cups-browsed
UpgradeStatus: Upgraded to lunar on 2023-03-29 (36 days ago)
dmi.bios.date: 11/24/2022
dmi.bios.release: 1.57
dmi.bios.vendor: LENOVO
dmi.bios.version: N1MET72W (1.57 )
dmi.board.asset.tag: Not Available
dmi.board.name: 20HRCTO1WW
dmi.board.vendor: LENOVO
dmi.board.version: Not Defined
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: None
dmi.ec.firmware.release: 1.22
dmi.modalias: dmi:bvnLENOVO:bvrN1MET72W(1.57):bd11/24/2022:br1.57:efr1.22:svnLENOVO:pn20HRCTO1WW:pvrThinkPadX1Carbon5th:rvnLENOVO:rn20HRCTO1WW:rvrNotDefined:cvnLENOVO:ct10:cvrNone:skuLENOVO_MT_20HR_BU_Think_FM_ThinkPadX1Carbon5th:
dmi.product.family: ThinkPad X1 Carbon 5th
dmi.product.name: 20HRCTO1WW
dmi.product.sku: LENOVO_MT_20HR_BU_Think_FM_ThinkPad X1 Carbon 5th
dmi.product.version: ThinkPad X1 Carbon 5th
dmi.sys.vendor: LENOVO

See original description
Revision history for this message
James Henstridge (jamesh) wrote :
description: updated
Revision history for this message
Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in cups-browsed (Ubuntu):
status: New → Confirmed
Daniel van Vugt (vanvugt)
Changed in cups-browsed (Ubuntu):
importance: Undecided → High
Revision history for this message
James Henstridge (jamesh) wrote :

Running strace on the running cups-browsed shows it repeatedly calling poll() with a zero timeout:

    poll([{fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 2, 0) = 0 (Timeout)
    poll([{fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 2, 0) = 0 (Timeout)
    poll([{fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 2, 0) = 0 (Timeout)
    poll([{fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 2, 0) = 0 (Timeout)
    ...

Here, fd 5 is an eventfd and fd 6 is a connection to the D-Bus system bus.

Revision history for this message
Marco Trevisan (Treviño) (3v1n0) wrote (last edit ):
Download full text (10.7 KiB)

Attaching to it, we're just polling in various threads and one was doing:

(gdb) info threads
  Id Target Id Frame
* 1 Thread 0x7ff453b2bb00 (LWP 2334) "cups-browsed" cupsArrayCurrent (a=0x56036f7aaae0)
    at /build/cups-h3QGh2/cups-2.4.2/cups/array.c:283
  2 Thread 0x7ff453aff6c0 (LWP 2360) "pool-spawner" syscall ()
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
  3 Thread 0x7ff44b2fe6c0 (LWP 2361) "gmain" 0x00007ff45590fd7f in __GI___poll (fds=0x56036f7a3440,
    nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
  4 Thread 0x7ff4532fe6c0 (LWP 2362) "gdbus" 0x00007ff45590fd7f in __GI___poll (fds=0x7ff43c000b90,
    nfds=2, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29

#0 cupsArrayCurrent (a=0x56036f7aaae0) at /build/cups-h3QGh2/cups-2.4.2/cups/array.c:283
#1 0x00007ff455e4d4bb in cupsArrayNext (a=<optimized out>) at /build/cups-h3QGh2/cups-2.4.2/cups/array.c:828
#2 0x000056036efa5b2c in remove_printer_entry (p=0x7ff440029650) at daemon/cups-browsed.c:8137
#3 0x000056036efaa786 in update_cups_queues (unused=<optimized out>) at daemon/cups-browsed.c:9637
#4 0x00007ff455ae6a42 in g_timeout_dispatch
    (source=0x56036f7da260, callback=<optimized out>, user_data=<optimized out>) at ../../../glib/gmain.c:5054
#5 0x00007ff455ae636f in g_main_dispatch (context=0x56036f7aac90) at ../../../glib/gmain.c:3460
#6 g_main_context_dispatch (context=0x56036f7aac90) at ../../../glib/gmain.c:4200
#7 0x00007ff455b41178 in g_main_context_iterate.constprop.0
    (context=0x56036f7aac90, block=<optimized out>, dispatch=1, self=<optimized out>)
    at ../../../glib/gmain.c:4276
#8 0x00007ff455ae5bdf in g_main_loop_run (loop=0x56036f7ba6d0) at ../../../glib/gmain.c:4479
#9 0x000056036ef943ff in main (argc=<optimized out>, argv=<optimized out>) at daemon/cups-browsed.c:14077

Thread 1 "cups-browsed" received signal SIGINT, Interrupt.
cupsArrayNext (a=0x56036f7aaae0) at /build/cups-h3QGh2/cups-2.4.2/cups/array.c:813
813 /build/cups-h3QGh2/cups-2.4.2/cups/array.c: Bad file descriptor.
(gdb) bt
#0 cupsArrayNext (a=0x56036f7aaae0) at /build/cups-h3QGh2/cups-2.4.2/cups/array.c:813
#1 0x000056036efaa0c4 in update_cups_queues (unused=<optimized out>) at daemon/cups-browsed.c:9310
#2 0x00007ff455ae6a42 in g_timeout_dispatch
    (source=0x56036f7da260, callback=<optimized out>, user_data=<optimized out>) at ../../../glib/gmain.c:5054
#3 0x00007ff455ae636f in g_main_dispatch (context=0x56036f7aac90) at ../../../glib/gmain.c:3460
#4 g_main_context_dispatch (context=0x56036f7aac90) at ../../../glib/gmain.c:4200
#5 0x00007ff455b41178 in g_main_context_iterate.constprop.0
    (context=0x56036f7aac90, block=<optimized out>, dispatch=1, self=<optimized out>)
    at ../../../glib/gmain.c:4276
#6 0x00007ff455ae5bdf in g_main_loop_run (loop=0x56036f7ba6d0) at ../../../glib/gmain.c:4479
#7 0x000056036ef943ff in main (argc=<optimized out>, argv=<optimized out>) at daemon/cups-browsed.c:14077

#0 0x00007ff45589dfd8 in _int_malloc (av=av@entry=0x7ff4559f6c80 <main_arena>, bytes=bytes@entry=4)
    at ./malloc/malloc.c:3839
#1 0x0...

Revision history for this message
James Henstridge (jamesh) wrote :

I was probably stracing that thread #0. It looks like the timeout in question can be added with a zero second delay, which would match up with the poll calls with a zero timeout:

https://github.com/OpenPrinting/cups-browsed/blob/1921fa792c01278068f5e19535c2479959187b09/daemon/cups-browsed.c#L9650-L9691

The update_cups_queues function ends by calling recheck_timer() again, likely scheduling another zero second timeout right away.

Revision history for this message
James Henstridge (jamesh) wrote :

In case it helps with debugging, here's the list of printers advertised via mDNS on this network as reported by "avahi-browse -rt _ipp._tcp".

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

@jamesh, could you also add the output of

avahi-browse -rt _ipps._tcp

It happens more and more often that services are IPPS-only.

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Thanks for all the helpful information to help solving the bug, but what I also really need is a debug log.

To create one, please edit the file

/etc/cups/cups-browsed.conf

to have a line

DebugLogging file

You usually only need to find the appropriate line and remove the '#' in the beginning.

The restart cups-browsed:

sudo systemctl stop cups-browsed
sudo systemctl start cups-browsed

Now observe your CPU, if cups-browsed takes a significant share again, please copy the file

/var/log/cups-browsed/cups-browsed_log

and attach it here. Do not compress it and do not package it together with other files.

Changed in cups-browsed (Ubuntu):
status: Confirmed → Incomplete
Revision history for this message
Ryan C. Underwood (nemesis-icequake) wrote :

The log file is massive and the root cause seems to be:
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328
Thu May 18 11:37:16 2023 140380723219200 update_cups_queues() in THREAD 140380754217328

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Ryan, thanks for the log file. Unfortunately there is only a little stub in the beginning readable and the rest is all zeros. Could you re-test (stop cups-browsed, delete log file, start cups-browsed) and then, after cups-browsed is taking up CPU again, stop cups-browsed, copy the file, check whether it is not damaged, and then attach it? Thanks.

Revision history for this message
Ryan C. Underwood (nemesis-icequake) wrote :

I think the problem is that the messages are being spammed so fast the log file is being continuously rotated. Is there a way to quickly disable that? Otherwise, I think even in the segment I uploaded one can see that it's the same repetitive messages over and over again, each group starting with the update_cups_queues() message.

Revision history for this message
Marius Gedminas (mgedmin) wrote :

Today I noticed cups-browsed eating 100% CPU for a while (about 20 minutes). I restarted it with 'sudo service cups-browsed restart', which took 1 minute 36 seconds (presumably cups-browsed didn't want to be restarted so systemd killed it forcefully after a 1m30s timeout?).

I have

    DebugLogging file stderr

in my /etc/cups/cups-browsed.conf from a previous debugging attempts (for a different problem). /var/log/cups-browsed/cups-browsed_log contains messages from after the restart (with no CPU eating problems), so here's /var/log/cups-browsed/cups-browsed_previous_logs. The relevant time interval is from Fri May 19 09:04:15 2023, when I resumed my laptop in the office, until the end.

It doesn't look very informative to me: a bunch of HTTP timeouts, an EINVAL, a IPP-Cancel-Subscription (whatever that means), and then complete silence until it gets a SIGTERM.

Revision history for this message
James Henstridge (jamesh) wrote :

@Till: I haven't been able to reproduce the problem post-sprint. But I don't have any other systems on my network advertising CUPS queues. I was only seeing it at the sprint

I'm not sure why you switched this to incomplete though: you've got multiple confirmations of the bug and stack traces indicating where in the code it is busy-looping.

Given that some of the advertised print queues were from your laptop, have you been able to reproduce this on your home network?

Revision history for this message
Francois Thirioux (fthx) wrote :

This issue happens (for me) only connected to (large) enterprise network.
Never see this at home.

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

To stop the rotating of the log file, near the end of /etc/cups/cups-browsed.conf you find

# DebugLogFileSize 300

replace this by

DebugLogFileSize 0

stop cups-browsed, delete the log file, and start cups-browsed.

James Henstridge (jamesh)
Changed in cups-browsed (Ubuntu):
status: Incomplete → Confirmed
Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

@jamesh, I had set it to "Incomplete" because I asked for debug logs, which are important in addition to what got already posted.

I tried to also reproduce it by myself, having the same IPP print services as on the sprint, plus my printer at home, providing two more IPP services (via network and via IPP-over-USB), but for me cups-browsed worked correctly. In my log appears the "Listening" which tells that for none of the handled remote printers any action is scheduled.

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

And on my system the CUPS Snap is running, in proxy mode (what usually happens if you install a Snap of an app which prints, and therefore plugs "cups").

Revision history for this message
Ryan C. Underwood (nemesis-icequake) wrote :

I changed that option and multiple gigabytes of logs were produced within minutes. It's the same repetitive output. How do you want to receive this log, if it's really necessary to demonstrate the problem?

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Ryan, as I do not have an idea yet why cups-browsed is mis-behaving this log would be actually helpful for me. Please xz-compress it and then attach it to this bug report. Thanks in advance.

Revision history for this message
Adam Dingle (adam-yorba) wrote :

I'm running Ubuntu 23.04 in a university environment with several printers on the local network. This morning I performed the following steps:

1. I stopped cups-browsed.
2. I edited the configuration file to have "DebugLogging file" and "DebugLogFileSize 0".
3. I started cups-browsed. It created a log file /var/log/cups-browsed/cups-browsed_log, and did not appear to be using an usual amount of CPU.
4. I unplugged the network cable from my laptop, then plugged it back in. Immediately cups-browsed started using 100% CPU. It appears that at the same time, the previous log file was renamed to cups-browsed_previous_logs, and a new log file cups-browsed_log was created.
5. I let cups-browsed run with 100% CPU for a couple of minutes. It didn't seem to write a huge amount of log output.
6. I stopped cups-browsed.

I'll attach both cups-browsed_log and cups-browsed_previous_logs.

Revision history for this message
Adam Dingle (adam-yorba) wrote :

cups-browsed_log

Revision history for this message
Adam Dingle (adam-yorba) wrote :

cups-browsed_previous_logs

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

@Adam, thanks for doing the tests, but it seems that your log files are still limited to 300 kb. Did you actually remove the "#" in the beginning of the configuration file lines which you have changed? Did you actually stop and restart the daemon?

Could you do

sudo systemctl stop cups-browsed
sudo rm /var/log/cups-browsed/*
sudo systemctl start cups-browsed

and then do your testing again and as soon as cups-browsed grabs significant CPU, stop it and attach all files in /var/log/cups-browsed/? If the files are to large for upload, xz-compress them.

Revision history for this message
Adam Dingle (adam-yorba) wrote :

Ah, yes, this was my mistake - I had "DebugLogFileSize 300" instead of "DebugLogFileSize 0". Sorry about that. I'll now attempt to repeat the experiment.

Revision history for this message
Adam Dingle (adam-yorba) wrote :

OK - I set "DebugLogFileSize 0", then repeated the experiment. Unfortunately this time cups-browsed did not use a significant amount of CPU, even after I repeatedly disconnected and reconnected from the network. So I have no useful log file for you at this time. :(

I'll keep running with debug logging, and if I see 100% CPU again I'll submit the log file(s) here.

Revision history for this message
James Henstridge (jamesh) wrote :

This is just a wild guess, but the avahi service listing from the sprint and Adam's and Marius's logs show that they're running in a dual stack environment. The avahi-browse dump shows the same queues being advertised on both IPv4 and IPv6 with the same mDNS service and host names.

Is it possible that cups-browsed is confusing these two advertisements, and leaving some job around that keeps re-queuing the idle function?

@Till: if you can't reproduce on your home network, is that network dual stack?

For others: does disabling IPv6 (or v4) locally and restarting cups-browsed make it behave differently?

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

@jamesh, I also have both IPv4 and IPv6 here, and did not yet run into the problem.

Generally, we check duplicate DNS-SD records from the same device, caused by IPv4/6, IPP/IPPS, and several network interfaces (localhost, Wi-Fi, Ethernet, VM managers, ...). So for each discovered print destination we create only one local queue, using the most desirable way of access.

There could perhaps be a bug in this facility. Especially we need to track all DNS-SD records for the device appearing and disappearing to relably tell whether the device has really gone away when it disappears.

Revision history for this message
Ryan C. Underwood (nemesis-icequake) wrote :

Full log attached

Revision history for this message
Francois Thirioux (fthx) wrote :

Don't know if this helps, I'm connected (dock-ethernet) to University network and I run this bug again (and again).

In logs I get a lot of:
AVC apparmor="DENIED" operation="connect" class="file" profile="/usr/sbin/cups-browsed" name="/run/systemd/resolve/io.systemd.Resolve" pid=1948 comm="cups-browsed" requested_mask="wr" denied_mask="wr" fsuid=123 ouid=101

Note I do run gufw public profile, don't know if it's related.

Revision history for this message
Marius Gedminas (mgedmin) wrote :
Download full text (5.8 KiB)

Got the bug again. The log is silent again, after the HTTP timeout messages. sysprof says that all the time is spent in httpGets, but I don't get meaningful stack traces (because Ubuntu builds with -fomit-frame-pointer probably). perf top shows the same.

Attaching with gdb shows me this for the main thread:

#0 __futex_abstimed_wait_common
    (cancel=false, private=<optimized out>, abstime=0x0, clockid=0, expected=3, futex_word=0x557767016e6c <lock+12>)
    at ./nptl/futex-internal.c:103
#1 __GI___futex_abstimed_wait64
    (futex_word=futex_word@entry=0x557767016e6c <lock+12>, expected=expected@entry=3, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=<optimized out>) at ./nptl/futex-internal.c:128
#2 0x00007f1235a9566c in __pthread_rwlock_wrlock_full64 (abstime=0x0, clockid=0, rwlock=0x557767016e60 <lock>)
    at ./nptl/pthread_rwlock_common.c:730
#3 ___pthread_rwlock_wrlock (rwlock=rwlock@entry=0x557767016e60 <lock>) at ./nptl/pthread_rwlock_wrlock.c:26
#4 0x0000557766ff4a54 in get_local_printers () at daemon/cups-browsed.c:4021
#5 0x0000557766fffab5 in update_local_printers.part.0.lto_priv.0 () at daemon/cups-browsed.c:4383
#6 0x0000557766ff886d in update_local_printers () at daemon/cups-browsed.c:7103
#7 on_printer_deleted
    (object=<optimized out>, text=<optimized out>, printer_uri=<optimized out>, printer_state=<optimized out>, printer_state_reasons=<optimized out>, printer_is_accepting_jobs=<optimized out>, user_data=<optimized out>, printer=0x55776866ac00 "HP_Color_LaserJet_MFP_M477fdw_fridge") at daemon/cups-browsed.c:7111
#8 on_printer_deleted
    (object=<optimized out>, text=0x5577686e7260 "Printer \"HP_Color_LaserJet_MFP_M477fdw_fridge\" deleted by \"cups-browsed\".", printer_uri=<optimized out>, printer=0x55776866ac00 "HP_Color_LaserJet_MFP_M477fdw_fridge", printer_state=<optimized out>, printer_state_reasons=<optimized out>, printer_is_accepting_jobs=1, user_data=0x0) at daemon/cups-browsed.c:7082
#9 0x00007f1235c158b6 in ffi_call_unix64 () at ../src/x86/unix64.S:104
#10 0x00007f1235c1234d in ffi_call_int
    (cif=cif@entry=0x7fffc989bd00, fn=<optimized out>, rvalue=<optimized out>, avalue=<optimized out>, closure=closure@entry=0x0) at ../src/x86/ffi64.c:673
#11 0x00007f1235c14f33 in ffi_call
    (cif=cif@entry=0x7fffc989bd00, fn=fn@entry=0x557766ff8750 <on_printer_deleted>, rvalue=rvalue@entry=0x7fffc989bc80, avalue=avalue@entry=0x7fffc989bbe0) at ../src/x86/ffi64.c:710
#12 0x00007f1235f87163 in g_cclosure_marshal_generic
    (closure=<optimized out>, return_gvalue=<optimized out>, n_param_values=<optimized out>, param_values=<optimized out>, invocation_hint=<optimized out>, marshal_data=<optimized out>) at ../../../gobject/gclosure.c:1536
#13 0x00007f1235f81010 in g_closure_invoke
    (closure=0x5577686e76a0, return_value=0x0, n_param_values=7, param_values=0x55776870a660, invocation_hint=0x7fffc989be80)
    at ../../../gobject/gclosure.c:832
#14 0x00007f1235fae3d6 in signal_emit_unlocked_R.isra.0 (node=<optimized out>, detail=0,
    detail@entry=3381248240, instance=0x5577686def10, emission_return=emission_return@entry=0x0, instance_and_params=0x55776870a660) at ../../../gobject/gsignal.c:3802
#1...

Read more...

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Thanks to all of you for providing log files. They have helped me to spot the actual bug which got introduced by the addition of multi-threading to cups-browsed, which got only included in the 2.x releases and not into the 1.x releases used by Ubuntu 22.10 and older.

I will commit a fix soon.

Changed in cups-browsed (Ubuntu):
status: Confirmed → In Progress
Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

I have found a possible fix for this bug.

Please try the cups-browsed 2.0~rc1-0ubuntu1.0ppa1 on my PPA:

https://launchpad.net/~till-kamppeter/+archive/ubuntu/ppa

and tell here whether it solves the problem. Thanks.

Revision history for this message
Nate Eldredge (nate-thatsmathematics) wrote :

cups-browsed 2.0~rc1-0ubuntu1.0ppa1 fixes the problem for me (23.04, x86-64). I was previously seeing cups-browsed stuck at 25% CPU, and with the new version this no longer happens.

Revision history for this message
Francois Thirioux (fthx) wrote :

Solved for me too.

Till Kamppeter (till-kamppeter)
description: updated
Till Kamppeter (till-kamppeter)
Changed in cups-browsed (Ubuntu Lunar):
status: New → In Progress
importance: Undecided → High
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package cups-browsed - 2.0~rc1-0ubuntu2

---------------
cups-browsed (2.0~rc1-0ubuntu2) mantic; urgency=medium

  * Fixed handling of failures when creating local print queues. On
    a failure a global variable was set by the queue creation function
    running as background thread, to stop the loop for updating the
    local queues, but the variable was never reset, making no local
    queue updates done any more for the rest of the life of the
    daemon, making the daemon falling into a busy loop. Completely
    done away with the variable. It is actually not needed (LP: #2018504).

 -- Till Kamppeter <email address hidden> Sun, 4 Jun 2023 18:50:57 +0200

Changed in cups-browsed (Ubuntu):
status: In Progress → Fix Released
Revision history for this message
Łukasz Zemczak (sil2100) wrote : Please test proposed package

Hello James, or anyone else affected,

Accepted cups-browsed into lunar-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/cups-browsed/2.0~rc1-0ubuntu1.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, what testing has been performed on the package and change the tag from verification-needed-lunar to verification-done-lunar. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-lunar. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

Changed in cups-browsed (Ubuntu Lunar):
status: In Progress → Fix Committed
tags: added: verification-needed verification-needed-lunar
Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Nate and François, even that you have tested the version from my PPA, please also install and test the proposed version in Łukasz' comment, to verify it for this SRU. Thanks.

Revision history for this message
Angel D. Segarra (angel-segarra) wrote (last edit ):

In my case this is happening in Lunar with a "AirPrint" printer connected through wifi, so there is no server pc sharing printer involved. This is usually triggered for me on reboot most of the time, with the propsed package 2.0~rc1-0ubuntu1.1 i did not see it happen. I also killed the power to the printer and do not see the issue happen.

tags: added: verification-done-lunar
removed: verification-needed-lunar
Revision history for this message
Brian Murray (brian-murray) wrote : Update Released

The verification of the Stable Release Update for cups-browsed has completed successfully and the package is now being released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package cups-browsed - 2.0~rc1-0ubuntu1.1

---------------
cups-browsed (2.0~rc1-0ubuntu1.1) lunar; urgency=medium

  * Fixed handling of failures when creating local print queues. On
    a failure a global variable was set by the queue creation function
    running as background thread, to stop the loop for updating the
    local queues, but the variable was never reset, making no local
    queue updates done any more for the rest of the life of the
    daemon, making the daemon falling into a busy loop. Completely
    done away with the variable. It is actually not needed (LP: #2018504).

 -- Till Kamppeter <email address hidden> Sun, 4 Jun 2023 18:50:57 +0200

Changed in cups-browsed (Ubuntu Lunar):
status: Fix Committed → Fix Released
Revision history for this message
hugh chao (hugh712) wrote :

Hi,

My PC is in 23.04, only one printer in this home environment,
and the cpus-browsed is 2.0~rc1-0ubuntu1.1,
I am not sure this is the same bug, but I have been hearing noise from the CPU fan this whole evening,
the CPU usage is high (around 100%, sometimes go up to 200%).

$avahi-browse -rt _ipps._tcp
+ eno1 IPv6 HP LaserJet M203dw (E371E7) Secure Internet Printer local
+ eno1 IPv4 HP LaserJet M203dw (E371E7) Secure Internet Printer local
= eno1 IPv4 HP LaserJet M203dw (E371E7) Secure Internet Printer local
   hostname = [NPIE371E7.local]
   address = [192.168.1.119]
   port = [631]
   txt = ["mopria-certified=1.3" "mac=e8:d8:d1:e3:71:e7" "usb_MDL=HP LaserJet M203-M206" "usb_MFG=HP" "TLS=1.2" "PaperMax=legal-A4" "kind=document,envelope,photo" "UUID=564e4233-4c30-3030-3735-e8d8d1e371e7" "Fax=F" "Scan=F" "Duplex=T" "Color=F" "note=unitedStates" "adminurl=https://NPIE371E7.local./hp/device/info_config_AirPrint.html?tab=Networking&menu=AirPrintStatus" "priority=10" "product=(HP LaserJet M203-M206)" "ty=HP LaserJet M203-M206" "URF=V1.4,CP99,W8,OB10,PQ3-4-5,DM1,IS1,MT1-3-5,RS600" "rp=ipp/print" "pdl=image/urf,application/PCLm,application/octet-stream,application/pdf,application/postscript,application/vnd.hp-PCL,application/vnd.hp-PCLXL,image/jpeg" "qtotal=1" "txtvers=1"]
= eno1 IPv6 HP LaserJet M203dw (E371E7) Secure Internet Printer local
   hostname = [NPIE371E7.local]
   address = [192.168.1.119]
   port = [631]
   txt = ["mopria-certified=1.3" "mac=e8:d8:d1:e3:71:e7" "usb_MDL=HP LaserJet M203-M206" "usb_MFG=HP" "TLS=1.2" "PaperMax=legal-A4" "kind=document,envelope,photo" "UUID=564e4233-4c30-3030-3735-e8d8d1e371e7" "Fax=F" "Scan=F" "Duplex=T" "Color=F" "note=unitedStates" "adminurl=https://NPIE371E7.local./hp/device/info_config_AirPrint.html?tab=Networking&menu=AirPrintStatus" "priority=10" "product=(HP LaserJet M203-M206)" "ty=HP LaserJet M203-M206" "URF=V1.4,CP99,W8,OB10,PQ3-4-5,DM1,IS1,MT1-3-5,RS600" "rp=ipp/print" "pdl=image/urf,application/PCLm,application/octet-stream,application/pdf,application/postscript,application/vnd.hp-PCL,application/vnd.hp-PCLXL,image/jpeg" "qtotal=1" "txtvers=1"]

Revision history for this message
Rodrigo Lledó (rodhos-hp) wrote :

Hi,

I'm still having this issue with cups-browsed - 2.0~rc1-0ubuntu1.1

Revision history for this message
Alan Pope 🍺🐧🐱 🦄 (popey) wrote :

Sorry to 'me too', but I also don't think this is fixed. I'm on Ubuntu 23.04, and after 3 days of uptime, cups-browsed is eating one of my eight cores. See screenshot.

Revision history for this message
Francois Thirioux (fthx) wrote :

Not fixed in Mantic.
I hit this bug at work, enterprise network.

Revision history for this message
Angel D. Segarra (angel-segarra) wrote :

According to https://bugs.launchpad.net/ubuntu/+source/cups-browsed/+bug/2018504/comments/39 this bug report is no longer being monitored, can someone still affected file a new report as specified in the above referenced comment?

Revision history for this message
Tim Richardson (tim-richardson) wrote :

Perhaps this bug should be reopened. I have one of my cores 100% occupied by cups-browser in Mantic.
cups-browsed (2.0.0-0ubuntu2) mantic; urgency=medium
which is a lot of power on a laptop.

The symptoms are the same, what are the chances that this is a brand new bug? Can we narrow down which debugging information is most helpful just in case it is the same bug, not yet fixed?

For my part, I will if I can reproduce it. Then I will follow the steps taken earlier in this report to rest various things (disabling IPV6) and seeing which log files were helpful. One of the comments reported that the log was "silent" which doesn't sound like it was very helpful.

Revision history for this message
Francois Thirioux (fthx) wrote :

Yes clearly, we have to reopen it.

That's a chance you report against it because I hit again this bug yesterday and did not remember the main bug about this.

That's a somewhat critical bug for laptop users. Same here: cups-browsed using 200 % (means here 1 entire core). Happens probably often as I can see that my laptop shows a somewhat bad (and random) estimated battery usage.

Well, it happens when I'm connected to my work's network. There are a lot of printers available.
It does not happen at home (only 1 printer).

Revision history for this message
Adam Dingle (adam-yorba) wrote :

I'm seeing this too. I'm running Ubuntu 23.10 (Mantic) with cups-browsed 2.0.0-0ubuntu2. This morning I brought my laptop to the university where I work, and when I connected it to the local network, cups-browsed started using 100% CPU, and is still now.

I'll attach the last 2000 lines of /var/log/cups-browsed_log. In this log file, 06:42:45 is the moment when I arrived in my office and connected my laptop to the network.

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Can please everyone who is still observing cups-browsed to take high CPU loads (100%, 200%, ...) follow my instructions in comment #8 and comment #15 to obtain a debug log and attach it to this bug report?

Also run the commands

    $ avahi-browse -rt _ipps._tcp
    $ avahi-browse -rt _ipp._tcp

and post their poutput.

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

@adam-yorba it seems that Network Manager is hammering your cups-browsed with several signals per second. Could you check the behavior of cups-browsed with Network Manager (network-manager) stopped?

Revision history for this message
Adam Dingle (adam-yorba) wrote :

@till-kamppeter Unfortunately it's difficult for me to test this, because I see this bug only intermittently, maybe once every month or two, and only when I take my laptop from home to the university where I work and connect to the network there. When I see this happen again, I will try to investigate a bit more.

Revision history for this message
Alex Cruise (acruise) wrote (last edit ):
Download full text (3.4 KiB)

I was seeing 200% until I kill-9'd cups-browsed, sorry if that makes it harder to collect info. But I still have this from scrollback:

alex@alex-work-pc:/var/log/cups-browsed$ avahi-browse -rt _ipps._tcp
+ enp1s0 IPv6 Canon MB5100 series Secure Internet Printer local
+ enp1s0 IPv4 Canon MB5100 series Secure Internet Printer local
= enp1s0 IPv6 Canon MB5100 series Secure Internet Printer local
   hostname = [Printer.local]
   address = [192.168.0.241]
   port = [631]
   txt = ["rfo=ipp/faxout" "TLS=1.2" "mopria-certified=1.2" "print-wfds=T" "PaperMax=legal-A4" "kind=document,envelope,photo,label" "Fax=T" "Scan=T" "Duplex=T" "Color=T" "UUID=00000000-0000-1000-8000-84BA3B777EB7" "URF=V1.4,CP1,PQ4-5,RS600,SRGB24,W8,OB9,OFU0,DM3,IS1" "usb_CMD=URF" "usb_MDL=MB5100 series" "usb_MFG=Canon" "adminurl=http://Printer.local./index.html?page=PAGE_AAP" "note=" "pdl=application/octet-stream,image/urf,image/jpeg,image/pwg-raster" "product=(Canon MB5100 series)" "ty=Canon MB5100 series" "priority=15" "qtotal=1" "rp=ipp/print" "txtvers=1"]
= enp1s0 IPv4 Canon MB5100 series Secure Internet Printer local
   hostname = [Printer.local]
   address = [192.168.0.241]
   port = [631]
   txt = ["rfo=ipp/faxout" "TLS=1.2" "mopria-certified=1.2" "print-wfds=T" "PaperMax=legal-A4" "kind=document,envelope,photo,label" "Fax=T" "Scan=T" "Duplex=T" "Color=T" "UUID=00000000-0000-1000-8000-84BA3B777EB7" "URF=V1.4,CP1,PQ4-5,RS600,SRGB24,W8,OB9,OFU0,DM3,IS1" "usb_CMD=URF" "usb_MDL=MB5100 series" "usb_MFG=Canon" "adminurl=http://Printer.local./index.html?page=PAGE_AAP" "note=" "pdl=application/octet-stream,image/urf,image/jpeg,image/pwg-raster" "product=(Canon MB5100 series)" "ty=Canon MB5100 series" "priority=15" "qtotal=1" "rp=ipp/print" "txtvers=1"]

alex@alex-work-pc:/var/log/cups-browsed$ avahi-browse -rt _ipp._tcp
+ enp1s0 IPv6 Canon MB5100 series Internet Printer local
+ enp1s0 IPv4 Canon MB5100 series Internet Printer local
= enp1s0 IPv4 Canon MB5100 series Internet Printer local
   hostname = [Printer.local]
   address = [192.168.0.241]
   port = [631]
   txt = ["rfo=ipp/faxout" "mopria-certified=1.2" "print-wfds=T" "PaperMax=legal-A4" "kind=document,envelope,photo,label" "Fax=T" "Scan=T" "Duplex=T" "Color=T" "UUID=00000000-0000-1000-8000-84BA3B777EB7" "URF=V1.4,CP1,PQ4-5,RS600,SRGB24,W8,OB9,OFU0,DM3,IS1" "usb_CMD=URF" "usb_MDL=MB5100 series" "usb_MFG=Canon" "adminurl=http://Printer.local./index.html?page=PAGE_AAP" "note=" "pdl=application/octet-stream,image/urf,image/jpeg,image/pwg-raster" "product=(Canon MB5100 series)" "ty=Canon MB5100 series" "priority=15" "qtotal=1" "rp=ipp/print" "txtvers=1"]
= enp1s0 IPv6 Canon MB5100 series Internet Printer local
   hostname = [Printer.local]
   address = [192.168.0.241]
   port = [631]
   txt = ["rfo=ipp/faxout" "mopria-certified=1.2" "print-wfds=T" "PaperMax=legal-A4" "kind=document,envelope,photo,label" "Fax=T" "Scan=T" "Duplex=T" "Color=T" "UUID=00000000-0000-1000-8000-84BA3B777EB7" "URF=V1.4,CP1,PQ4-5,RS...

Read more...

Revision history for this message
Alex Cruise (acruise) wrote (last edit ):

One thing that may be relevant: I recently (2-3 days ago) updated my router's configuration to assign the printer a new DNS name. It's possible something got confused when the same MAC (or persistent IDs are visible via mDNS etc.) appeared under multiple DNS names.

Also note when I had this problem yesterday, I was on 23.10 with all updates applied, including cups-browsed 2.0.0-0ubuntu2

Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

If you still get excessive CPU usage by cups-browsed, especially if it takes 200% CPU, see bug 2049315.

Revision history for this message
Theo Döllmann (mctoel) wrote :
Download full text (15.6 KiB)

I'm having this problem too. It often starts when I'm in the university network. In my case, the cups-browsed takes 100% CPU. I'm running Ubuntu 23.10 and cups-browsed 2.0.0-0ubuntu2. If I can add anything usefull, please let me know, I have the issue about 1-2 times per week.

Here is my output of:
    avahi-browse -rt _ipps._tcp
    avahi-browse -rt _ipp._tcp

➜ ~ avahi-browse -rt _ipps._tcp
+ wlp0s20f3 IPv4 HP Fax 4 @ st-xps-9550 Secure Internet Printer local
+ wlp0s20f3 IPv4 HP OfficeJet Pro 8720 @ st-xps-9550 Secure Internet Printer local
+ wlp0s20f3 IPv4 HP Officejet 6500 E710n-z @ st-xps-9550 Secure Internet Printer local
+ wlp0s20f3 IPv4 Lexmark CS725 @ diracium Secure Internet Printer local
+ wlp0s20f3 IPv4 Brother MFC-L2710DW series @ MacBook Pro von Laura (2) Secure Internet Printer local
+ wlp0s20f3 IPv4 EPSON ET-2710 Series @ st-xps-9550 Secure Internet Printer local
+ wlp0s20f3 IPv4 EPSON WF-2830 Series @ Lisa___s MacBook Air (2) Secure Internet Printer local
+ wlp0s20f3 IPv4 Lexmark543 @ Kunstpaedagogiks MacBook Pro Secure Internet Printer local
+ wlp0s20f3 IPv4 Brother DCP-9022CDW @ MacBook Air von Amarela Secure Internet Printer local
+ wlp0s20f3 IPv4 HP Officejet 5740 series @ Sophias MacBook Pro (2) Secure Internet Printer local
+ wlp0s20f3 IPv4 EPSON XP-710 Series @ Karlottas MacBook Air Secure Internet Printer local
= wlp0s20f3 IPv4 HP Fax 4 @ st-xps-9550 Secure Internet Printer local
   hostname = [st-xps-9550.local]
   address = [172.21.67.94]
   port = [631]
   txt = ["printer-type=0x100E" "Color=T" "mopria-certified=1.3" "URF=V1.4,CP1,W8,PQ4,SRGB24,RS300,FN3" "TLS=1.2" "UUID=cb1415ea-c4a0-337d-41c8-62950cc7ba06" "pdl=application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf" "product=(HP Fax4)" "priority=0" "note=st-xps-9550" "adminurl=https://st-xps-9550.local.:631/printers/Officejet-6500-E710n-z-Fax-4" "ty=HP Fax4 hpcups" "rp=printers/Officejet-6500-E710n-z-Fax-4" "qtotal=1" "txtvers=1"]
= wlp0s20f3 IPv4 HP OfficeJet Pro 8720 @ st-xps-9550 Secure Internet Printer local
   hostname = [st-xps-9550.local]
   address = [172.21.67.94]
   port = [631]
   txt = ["printer-type=0x901E" "Duplex=T" "Color=T" "mopria-certified=1.3" "URF=V1.4,CP1,W8,PQ3-4-5,SRGB24,RS300,DM1,FN3" "TLS=1.2" "UUID=9a4dee91-d153-36da-4a4b-61c7633a39a8" "pdl=application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf" "product=(HP OfficeJet Pro 8720)" "priority=0" "note=" "adminurl=https://st-xps-9550.local.:631/printers/HP_OfficeJet_Pro_8720" "ty=HP OfficeJet Pro 8720, driverless, cups-filters 1.27.4" "rp=printers/HP_OfficeJet_Pro_8720" "qtotal=1" "txtvers=1"]
= wlp0s20f3 IPv4 HP Officejet 6500 E710n-z @ st-xps-9550 Secure Internet Printer local
   hostname = [st-xps-9550.local]
   address = [172.21.67.94]
   port = [631]
   txt = ["printer-type=0x901E" "Duplex=T" "Color=T" "mopria-certified=1.3" "URF=V1.4,CP1,W8,PQ4-5,SRGB24,RS300,DM1,FN3" "TLS=1.2" "UUID=dbeb1e61-85e3-3fba-76d4-c4e049c73090" "pdl=application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,imag...

Revision history for this message
Tim Duncan (ww3ib0sg-tim-8aw3u04u) wrote :

This has been happening to me about once a week the last several months. I'll be working on my laptop and notice it's getting hot on my knees and the fan is running on full. I check sensors and CPUs are at 80 C. I used to just reboot to fix but finally started checking top and it was always cups taking like 99% or sometimes even 199% CPU (assume this means all of two cores). After finding this I issue a kill to the cups PID and in just 10-15 seconds fan slows and in 30 seconds sometimes even goes off and CPU temps are back to low 40s after a minute.

I'm not sure what troubleshooting I can do to help with this but I install all updates same day I get notified so am as current as possible. I have one HP LaserJet printer on my home network but rarely print to it but it is always on.

lspci
00:00.0 Host bridge: Intel Corporation Device 4601 (rev 04)
00:02.0 VGA compatible controller: Intel Corporation Alder Lake-UP3 GT2 [Iris Xe Graphics] (rev 0c)
00:04.0 Signal processing controller: Intel Corporation Alder Lake Innovation Platform Framework Processor Participant (rev 04)
00:08.0 System peripheral: Intel Corporation 12th Gen Core Processor Gaussian & Neural Accelerator (rev 04)
00:14.0 USB controller: Intel Corporation Alder Lake PCH USB 3.2 xHCI Host Controller (rev 01)
00:14.2 RAM memory: Intel Corporation Alder Lake PCH Shared SRAM (rev 01)
00:15.0 Serial bus controller: Intel Corporation Alder Lake PCH Serial IO I2C Controller #0 (rev 01)
00:15.1 Serial bus controller: Intel Corporation Alder Lake PCH Serial IO I2C Controller #1 (rev 01)
00:16.0 Communication controller: Intel Corporation Alder Lake PCH HECI Controller (rev 01)
00:17.0 SATA controller: Intel Corporation Alder Lake-P SATA AHCI Controller (rev 01)
00:1c.0 PCI bridge: Intel Corporation Device 51bc (rev 01)
00:1d.0 PCI bridge: Intel Corporation Alder Lake PCI Express x1 Root Port #10 (rev 01)
00:1f.0 ISA bridge: Intel Corporation Alder Lake PCH eSPI Controller (rev 01)
00:1f.3 Multimedia audio controller: Intel Corporation Alder Lake PCH-P High Definition Audio Controller (rev 01)
00:1f.4 SMBus: Intel Corporation Alder Lake PCH-P SMBus Host Controller (rev 01)
00:1f.5 Serial bus controller: Intel Corporation Alder Lake-P PCH SPI Controller (rev 01)
01:00.0 Non-Volatile memory controller: Samsung Electronics Co Ltd NVMe SSD Controller 980
02:00.0 Network controller: Realtek Semiconductor Co., Ltd. RTL8821CE 802.11ac PCIe Wireless Network Adapter

Revision history for this message
Dan Egnor (egnor) wrote :
Download full text (4.3 KiB)

CPU is pegged at 200%, as it occasionally is. Log as requested attached.

=== output from `avahi-browse -rt _ipp._tcp` ===
+ wlp1s0 IPv6 oneprinting Internet Printer local
+ wlp1s0 IPv4 oneprinting Internet Printer local
= wlp1s0 IPv4 oneprinting Internet Printer local
   hostname = [HPF80DACD5800D.local]
   address = [192.168.50.133]
   port = [631]
   txt = ["Fax=T" "rfo=ipp/faxout" "mopria-certified=2.0" "Scan=T" "kind=document" "URF=CP1,MT1-2-8-9-10-11,PQ3-4-5,RS600,SRGB24,OB10,W8,DEVW8,DEVRGB24,ADOBERGB24,DM3,IS19-1-2,V1.4,FN3" "PaperMax=legal-A4" "pdl=application/vnd.hp-PCL,application/vnd.hp-PCLXL,application/postscript,application/msword,application/pdf,image/jpeg,image/urf,image/pwg-raster,application/PCLm,application/vnd.openxmlformats-officedocument.wordprocessingml.document,application/vnd.m" "Duplex=T" "Color=T" "usb_MDL=Color LaserJet Pro M478f-9f" "usb_MFG=HP" "ty=HP Color LaserJet Pro M478f-9f" "product=(HP Color LaserJet Pro M478f-9f)" "UUID=d716b122-d422-5796-0cda-a6a1f122f436" "rp=ipp/print" "TLS=1.2" "qtotal=1" "priority=20" "note=" "adminurl=http://HPF80DACD5800D.local./#hId-pgAirPrint" "txtvers=1"]
= wlp1s0 IPv6 oneprinting Internet Printer local
   hostname = [HPF80DACD5800D.local]
   address = [192.168.50.133]
   port = [631]
   txt = ["Fax=T" "rfo=ipp/faxout" "mopria-certified=2.0" "Scan=T" "kind=document" "URF=CP1,MT1-2-8-9-10-11,PQ3-4-5,RS600,SRGB24,OB10,W8,DEVW8,DEVRGB24,ADOBERGB24,DM3,IS19-1-2,V1.4,FN3" "PaperMax=legal-A4" "pdl=application/vnd.hp-PCL,application/vnd.hp-PCLXL,application/postscript,application/msword,application/pdf,image/jpeg,image/urf,image/pwg-raster,application/PCLm,application/vnd.openxmlformats-officedocument.wordprocessingml.document,application/vnd.m" "Duplex=T" "Color=T" "usb_MDL=Color LaserJet Pro M478f-9f" "usb_MFG=HP" "ty=HP Color LaserJet Pro M478f-9f" "product=(HP Color LaserJet Pro M478f-9f)" "UUID=d716b122-d422-5796-0cda-a6a1f122f436" "rp=ipp/print" "TLS=1.2" "qtotal=1" "priority=20" "note=" "adminurl=http://HPF80DACD5800D.local./#hId-pgAirPrint" "txtvers=1"]

=== output from `avahi-browse -rt _ipps._tcp` ===
+ wlp1s0 IPv6 oneprinting Secure Internet Printer local
+ wlp1s0 IPv4 oneprinting Secure Internet Printer local
= wlp1s0 IPv6 oneprinting Secure Internet Printer local
   hostname = [HPF80DACD5800D.local]
   address = [192.168.50.133]
   port = [631]
   txt = ["Fax=T" "rfo=ipp/faxout" "mopria-certified=2.0" "Scan=T" "kind=document" "URF=CP1,MT1-2-8-9-10-11,PQ3-4-5,RS600,SRGB24,OB10,W8,DEVW8,DEVRGB24,ADOBERGB24,DM3,IS19-1-2,V1.4,FN3" "PaperMax=legal-A4" "pdl=application/vnd.hp-PCL,application/vnd.hp-PCLXL,application/postscript,application/msword,application/pdf,image/jpeg,image/urf,image/pwg-raster,application/PCLm,application/vnd.openxmlformats-officedocument.wordprocessingml.document,application/vnd.m" "Duplex=T" "Color=T" "usb_MDL=Color LaserJet Pro M478f-9f" "usb_MFG=HP" "ty=HP Color LaserJet Pro M478f-9f" "product=(HP Color...

Read more...

Revision history for this message
Holden Karau (holden-pigscanfly) wrote :

+1 also running into this
If I restart cups the issue goes away for "awhile" though (interestingly printing does not seem to impact cups meaning it's probably behavior that is unrelated to the printing).

Revision history for this message
Raffaele Rialdi (raffaeler) wrote :

This should not be marked as fixed.
I'm on Ubuntu23.10 (desktop) with several desktop VMs (same OS) and even those that were just installed exhibit the issue with the CPU usate on cups-browsed on snap.
When I try to stop using those, it does not work and I have to reboot:
sudo snap stop cups
sudo snap disable cups

Please reopen the issue

Revision history for this message
Alexander Topic (alextopic) wrote :

Hello, I just observed this bug last night with Btop++. I noticed 1-2 Cores at 100% and my
cpu was over heating. I recently installed Ubuntu 24.04 LTS about a week ago and everything
has been some what working well, except this bug.

My room mate has wifi printers, so when they shutdown this can trigger this bug? I have a local Xerox B205 laser printer, but also have wifi printers.

I had to shutdown and reboot up, then it seemed to go away.

I hope this gets fixed soon, it is a waste of power and not good for us.

Good to know others reported this bug, thank you all.

Revision history for this message
Dade Murphy (h4ckth3pt4n3t) wrote (last edit ):

This just happened to me. Running Ubuntu 23.10. I believe it was shortly after I installed an update and chose to reboot. CPU fan was working hard so I shut down all programs, but it wouldn't stop. Ran htop and saw cups-browsed using 100% of 1 cpu, so I kill -9'd it and all was well.

Revision history for this message
Matthew Brozusky (mrman58) wrote :

I just went through the same thing Dade Murphy did. Only difference is I'm running on Ubuntu 24.04.

Revision history for this message
James Henstridge (jamesh) wrote :

Note that the problem this bug was opened to address was fixed in an update to 23.04.

If you are seeing a problem on 24.04, it is most likely a different issue (possibly bug 2049315). Comments on long closed bug reports are likely to be missed.

Revision history for this message
Raffaele Rialdi (raffaeler) wrote :

@James I am seeing the cups-browsed using 100% CPU on Ubuntu 23.10 fully updated
Initially the cups-browsed was running as a snap service, then I disabled it.
After this, Ubuntu installed a systemctl service that gets re-enabled after every reboot even if I disable it.

I repeat: the bug is not solved yet.
Thanks for understanding.

Revision history for this message
James Henstridge (jamesh) wrote :

@Raffaele: I'm not saying that there isn't a problem: rather that the cause is probably different to the one from this closed bug, even if the symptom is the same.

You'd be better off reporting a new bug, or looking through the open bug reports to see if any of those match what you're seeing.

Revision history for this message
Raffaele Rialdi (raffaeler) wrote :

@James Understood, but the symptoms are the same, including the printer disappearing from the network (turned off).
Should I find a similar problem or open a new one, the symptoms would be exactly the same. Not sure if a duplicate issue would help.

Revision history for this message
James Henstridge (jamesh) wrote :

Please file a new bug. If you run "ubuntu-bug cups-browsed" to start writing your report, it'll automatically include some relevant diagnostics. If there are any relevant log messages in the journal, that would be useful too.

Marking a bug as duplicate is very easy to do. Untangling two problems that have been mixed into one bug report is a lot harder.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.