cups-browsed causes shutdown hang/delay in Ubuntu 16.04

Bug #1579905 reported by Bill Miller
92
This bug affects 21 people
Affects Status Importance Assigned to Milestone
cups-filters (Ubuntu)
Medium
Unassigned
Xenial
Medium
Unassigned

Bug Description

[SRU justification]

When the system is shut down CUPS and cups-browsed are not shut down in a determined order, but cups-browsed needs CUPS still running to perform its shutdown, for removing the print queues it has generated and for saving information about these queues for use in the next session. With CUPS already shut down cups-browsed simply hangs and gets killed after a certain timeout. This can be fixed by defining the correct relationships in the systemd .service files and so the annoying hang can be avoided.

[Test case]

To reproduce the bug run

sudo systemctl stop cups

and after some seconds

sudo systemctl stop cups-browsed

with the shutdown of cups-browsed hanging.

On system shutdown one gets the hang, but not always as it can happen that on some shutdowns cups-browsed shuts down before cups.

After installing the fixed package, hhutting down cups requires shutting down cups-browsed before, so that the shutdown of cups triggers the shutdown of cups-browsed, making all shutdowns having the two services shut down in the right order avoiding a hang.

[Regression potential]

None. We only define a dependency between two services to make them shit down in the correct order.

[Original report]

Using the debug process found here https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1464917 I have determined that the cause of my 16.04 install's shutdown hang is cups-browsed. It was the only process running when I did a systemctl list-jobs in the VT9 shell. If I do sudo service cups-browsed stop and then shutdown, I do not get a hang.

I have confirmed this on a virtual machine and a real system. If I disable cups-browsed from ever starting, my problem is fixed.

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

Please attach your /etc/cups/cupsd.conf and /etc/cups/cups-browsed.conf files and post the output of

lpstat -v

once with cups-browsed running and once with cups-browsed stopped.

Also stop cups-browsed via

sudo service cups-browsed stop

and then start it from the command line via

sudo nohup /usr/sbin/cups-browsed --debug > /log.txt 2>&1 &

Shut down your system.

After starting your system again, attach /log.txt.

Attach all the files one by one, do not compress them and do not package them together.

Changed in cups (Ubuntu):
status: New → Incomplete
Revision history for this message
Bill Miller (wbmilleriii) wrote :

/etc/cups/cupsd.conf

Revision history for this message
Bill Miller (wbmilleriii) wrote :

/etc/cups/cups-browsed.conf

Revision history for this message
Bill Miller (wbmilleriii) wrote :

output of lpstat -v with cups-browsed running

Revision history for this message
Bill Miller (wbmilleriii) wrote :

Output of lpstat -v with cups-browsed not running

Revision history for this message
Bill Miller (wbmilleriii) wrote : Re: [Bug 1579905] Re: cups-browsed causes shutdown hang/delay in Ubuntu 16.04

When I run your command

sudo nohup /usr/sbin/cups-browsed --debug > /log.txt 2>&1 &

I get bash: /log.txt: Permission denied

I have uploaded the other files you requested.

On 05/09/2016 04:30 PM, Till Kamppeter wrote:
> sudo nohup /usr/sbin/cups-browsed --debug > /log.txt 2>&1 &

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

Please run

sudo -s

to get a root prompt. Then run

nohup /usr/sbin/cups-browsed --debug > /log.txt 2>&1 &

Shut down your system.

After starting your system again, attach /log.txt.

Revision history for this message
Bill Miller (wbmilleriii) wrote :

sudo -s
nohup /usr/sbin/cups-browsed --debug > /log.txt 2>&1 &

rebooted

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

Did the shutdown delay or hang during your test of comment #9?

Revision history for this message
Bill Miller (wbmilleriii) wrote :

Yes. I experienced the 1-2 minute delay / hang that I have seen since upgrading to 16.04.

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

I can reproduce the bug. cups-browsed hangs on shutdown when CUPS is not running any more. One can simply do

sudo systemctl stop cups

and after some seconds

sudo systemctl stop cups-browsed

with the shutdown of cups-browsed hanging.

Problem is that during shutdown cups-browsed accesses CUPS to remove print queues and save option settings.

Solution is to modify systemd *.service files to assure that on shutdown cups-browsed shuts down before CUPS.

Changed in cups (Ubuntu):
status: Incomplete → Triaged
Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Fix is to assure via systemd that cups-browsed is never running without CUPS running, especially to let cups-browsed always shut down before CUPS.

This can be reached by adding the line

Requires=cups.service

to the [Unit] section of

/lib/systemd/system/cups-browsed.service

and then to run

sudo systemctl daemon-reload

to make the change already working in the current session.

Please test.

affects: cups (Ubuntu) → cups-filters (Ubuntu)
Revision history for this message
Bill Miller (wbmilleriii) wrote :

Edited /lib/systemd/system/cups-browsed.service to look like this:

[Unit]
Description=Make remote CUPS printers available locally
After=cups.service avahi-daemon.service
Wants=cups.service avahi-daemon.service
Requires=cups.service

[Service]
ExecStart=/usr/sbin/cups-browsed

[Install]
WantedBy=multi-user.target

Did sudo systemctl daemon-reload

System hung on shutdown.

Rebooted, system hung on next shutdown.

Have to say it didn't work.

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

On my test I have added the line in the beginning of the [Unit] section:

[Unit]
Description=Make remote CUPS printers available locally
Requires=cups.service
After=cups.service avahi-daemon.service
Wants=cups.service avahi-daemon.service
...

Perhaps this makes some difference. Perhaps you should also try to remove cups.service from the Wabts= line in addition.

Revision history for this message
Bill Miller (wbmilleriii) wrote :

OK, with the "unit" section looking like this

[Unit]
Description=Make remote CUPS printers available locally
Requires=cups.service
After=cups.service avahi-daemon.service
Wants=avahi-daemon.service

It works! No hang.

Revision history for this message
Bill Miller (wbmilleriii) wrote :

But oops - it shutdown after editing the file, but shutdowns after a reboot still hang.

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

Can you attach your

/lib/systemd/system/cups.service

file?

Please also attach all your

/lib/systemd/system/cups.*
/lib/systemd/system/cups-browsed.*

and

/etc/systemd/system/cups.*
/etc/systemd/system/cups-browsed.*
/run/systemd/system/cups.*
/run/systemd/system/cups-browsed.*

as far as such files exist.

Please attach the files one by one, do not compress them and do not package them together.

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

Can you do another test? Try the following in

/lib/systemd/system/cups-browsed.service

[Unit]
Description=Make remote CUPS printers available locally
Requires=cups.service avahi-daemon.service
After=cups.service avahi-daemon.service
...

Does this work on reboot?

Revision history for this message
Bill Miller (wbmilleriii) wrote :

This didn't work either.

On 05/24/2016 09:40 AM, Till Kamppeter wrote:
> Can you do another test? Try the following in
>
> /lib/systemd/system/cups-browsed.service
>
> [Unit]
> Description=Make remote CUPS printers available locally
> Requires=cups.service avahi-daemon.service
> After=cups.service avahi-daemon.service
> ...
>
> Does this work on reboot?
>

Revision history for this message
Bill Miller (wbmilleriii) wrote :
Revision history for this message
Bill Miller (wbmilleriii) wrote :
Revision history for this message
Bill Miller (wbmilleriii) wrote :
Revision history for this message
Bill Miller (wbmilleriii) wrote :
Revision history for this message
Bill Miller (wbmilleriii) wrote :

There are no cups* files in /etc/systemd/system/ or /run/systemd/system/

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

Please add a line

Before=cups-browsed.service

to the [Unit] section of the /lib/systemd/system/cups.service file.

Does this solve the problem?

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

This bug was fixed in the package cups-filters - 1.9.0-1

---------------
cups-filters (1.9.0-1) unstable; urgency=medium

  * New upstream release
   - pdftopdf: Added functionality for logging pages in the
     /var/log/cups/page_log file. Logging can also be forced or suppressed via
     command line (page-logging=on/off/auto) and page logging is also done for
     filters which should do but actually do not do: foomatic-rip, gstopxl,
     hpps (CUPS issue #4798, LP: #1585380)
   - cups-browsed: Added "Requires=cups-service" to the cups-browsed.service
     file, so that systemd keeps CUPS running while shutting down cups-browsed
     on system shutdown (LP: #1579905)
   - cups-browsed/sys5ippprinter: Fixed documentation about the allowed input
     formats for auto-created network printer queues using sys5ippprinter, also
     improved NEWS entry about renaming of sys5ippprinter (Closes: #819665)

  [ Till Kamppeter ]
  * Added Conflicts:/Replaces:/Provides: foomatic-filters-beh to the
    cups-filters binary package due to the fact that the beh backend is now
    part of cups-filters (LP: #1563686, Closes: #816700)

  [ Didier Raboud ]
  * Bump S-V to 3.9.8 without changes needed

 -- Didier Raboud <email address hidden> Thu, 09 Jun 2016 22:16:37 +0200

Changed in cups-filters (Ubuntu):
status: Triaged → Fix Released
Revision history for this message
Joshua Gleitze (joshua-gleitze) wrote :

Will the fix (version 1.9.0 of cups-filters) be made available through the main PPA for Xenial?

Revision history for this message
Roger Mason (roger-mason) wrote :

When will cups-filters V 1.9.0 get added to 16.04.1 LTS updates? My cups-filters is still at 1.8.3-2ubuntu3 as of today's latest updates. I'm seeing the same failure to power off and used the same workaround process as reported by Bill Miller above.

Revision history for this message
mirohe (miguelrodriguezhernando) wrote :

Hello,

I Have the same problem, but I put in file cups-browsed.service the line: "Requires=cups.service avahi-daemon.service" and not fix the problem.

Revision history for this message
Martin Pitt (pitti) wrote :

Adding xenial task. Till, can you please prepare an SRU for this?

Changed in cups-filters (Ubuntu Xenial):
status: New → Triaged
description: updated
Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Uploaded an SRU fix for Xenial: cups-filters 1.8.3-2ubuntu3.1. As soon as it gets appoved into xenial-proposed Instructions for downloading and testing will get posted here. Note that testing it and giving feedback here is required for the fix getting into the official updates of Xenial.

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

debdiff of the fix.

Revision history for this message
Storm Scout (dibblecl) wrote :

Thank you Till. I had been dealing with 90 second shutdowns for the past week on Mint 18. I'm back to 4-5 second shutdowns now.

Changed in cups-filters (Ubuntu Xenial):
status: Triaged → Fix Committed
Revision history for this message
Martin Pitt (pitti) wrote : Please test proposed package

Hello Bill, or anyone else affected,

Accepted cups-filters into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/cups-filters/1.8.3-2ubuntu3.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 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, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

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

tags: added: verification-needed
Mathew Hodson (mhodson)
Changed in cups-filters (Ubuntu):
importance: Undecided → Medium
Changed in cups-filters (Ubuntu Xenial):
importance: Undecided → Medium
Revision history for this message
Bill Miller (wbmilleriii) wrote :

Installed from proposed

apt-cache policy cups-filters
cups-filters:
  Installed: 1.8.3-2ubuntu3.1
  Candidate: 1.8.3-2ubuntu3.1
  Version table:
 *** 1.8.3-2ubuntu3.1 400
        400 http://us.archive.ubuntu.com/ubuntu xenial-proposed/main i386 Packages
        100 /var/lib/dpkg/status
     1.8.3-2ubuntu3 500
        500 http://us.archive.ubuntu.com/ubuntu xenial/main i386 Packages

Testing in progress

Revision history for this message
Bill Miller (wbmilleriii) wrote :

As far as I can tell it works now.

I changed the tag at the top to verification-done...hope that's what was requested.

tags: added: verification-done
removed: verification-needed
Revision history for this message
Till Kamppeter (till-kamppeter) wrote :

Bill, that's it. Thank you for testing.

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

This bug was fixed in the package cups-filters - 1.8.3-2ubuntu3.1

---------------
cups-filters (1.8.3-2ubuntu3.1) xenial-proposed; urgency=medium

  * Added "Requires=cups-service" to the cups-browsed.service file to make
    cups-browsed always shut down before CUPS to avoid the system hanging
    during shutdown (LP: #1579905).

 -- Till Kamppeter <email address hidden> Thu, 18 Aug 2016 17:23:06 -0300

Changed in cups-filters (Ubuntu Xenial):
status: Fix Committed → Fix Released
Revision history for this message
Chris J Arges (arges) wrote : Update Released

The verification of the Stable Release Update for cups-filters has completed successfully and the package has now been 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
Till Kamppeter (till-kamppeter) wrote :

Note that there is also another cause for cups-browsed hanging on shutdown, which can also occur with the fix for this bug applied. It is reported to Debian here

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

It happens when CUPS is only listening on the domain socket and not on localhost:631 as cups-browsed then principally uses the domain socket in this case but at some points, especially during procedures of the shutdown, it uses localhost:631.

I have already fixed this problem and will issue cups-filters 1.11.3 with the fix soon and put it into Debian and Yakkety.

So if your cups-browsed still hangs, DO NOT re-open this bug, please report a new bug referring to the Debian bug here on Launchpad so that we can conduct another SRU there.

Revision history for this message
Bill Miller (wbmilleriii) wrote : Re: [Bug 1579905] Re: cups-browsed causes shutdown hang/delay in Ubuntu 16.04

Got it, thanks.
WM

On 09/03/2016 05:26 PM, Till Kamppeter wrote:
> Note that there is also another cause for cups-browsed hanging on
> shutdown, which can also occur with the fix for this bug applied. It is
> reported to Debian here
>
> https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=832637
>
> It happens when CUPS is only listening on the domain socket and not on
> localhost:631 as cups-browsed then principally uses the domain socket in
> this case but at some points, especially during procedures of the
> shutdown, it uses localhost:631.
>
> I have already fixed this problem and will issue cups-filters 1.11.3
> with the fix soon and put it into Debian and Yakkety.
>
> So if your cups-browsed still hangs, DO NOT re-open this bug, please
> report a new bug referring to the Debian bug here on Launchpad so that
> we can conduct another SRU there.
>
> ** Bug watch added: Debian Bug tracker #832637
> http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=832637
>

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

Other bug subscribers

Remote bug watches

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