cups upstart post-start script hangs forever when local socket is disabled

Bug #672438 reported by sutupud
64
This bug affects 12 people
Affects Status Importance Assigned to Milestone
cups (Ubuntu)
Fix Released
Low
Martin Pitt

Bug Description

Binary package hint: cups

the post-start script of the cupsd daemon waits for /var/run/cups/cups.sock to exist.
as it was my case, if listening on that socket is turned of in the configuration, the post-start script waits forever and trying to stop or restart the daemon via upstart tools fails.
shouldn't the script rather wait for /var/run/cups/cupsd.pid?

CVE References

Changed in cups (Ubuntu):
assignee: nobody → Martin Pitt (pitti)
Revision history for this message
Martin Pitt (pitti) wrote :

But you can just as well disable the pid file in cups. Disabling the local socket is pretty evil, since that will immediately break all the cups command line tools (you'd always have to specify "-h localhost"). Without the local socket there is no way that we can check when the daemon is ready to accept requests, and the remainder of the script won't work either.

Changed in cups (Ubuntu):
importance: Undecided → Low
status: New → Triaged
summary: - cups upstart post-start script not completing
+ cups upstart post-start script hangs forever when local socket is
+ disabled
Revision history for this message
Martin Pitt (pitti) wrote :

I think I'll just add a timeout and skip the coldplugging if that fails.

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

pitti, simply run the cold plug anyway after a timeout of 3 sec. After this time CUPS will be up for sure or not come up any more (crashed or in infinite loop). If cold plug fails then, let it fail non-fatally (warn in log file but do not "exit 1").

Martin Pitt (pitti)
Changed in cups (Ubuntu):
status: In Progress → Fix Committed
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package cups - 1.4.4-7

---------------
cups (1.4.4-7) unstable; urgency=low

  [ Till Kamppeter ]
  * debian/local/filters/pdf-filters/pdftopdf/parseargs.c,
    debian/local/filters/pdf-filters/pdftopdf/parseargs.cxx,
    debian/local/filters/pdf-filters/pdftopdf/parseargs.h,
    debian/local/filters/pdf-filters/pdftopdf/Makefile: Made pdftopdf
    building with Poppler 0.15.x. Thanks to Koji Otani for this patch.
  * debian/control: Added dependency on "cups-ppdc" package to the "cups"
    package, so that the PPDs of the drivers which come with CUPS get built
    (LP: #485383).

  [ Martin Pitt ]
  * ubuntu-upstart.dpatch: Wait until daemon is ready, to avoid race
    conditions with init scripts which expect cups tools to work right after
    restarting it. (LP: #647369)
  * ubuntu-upstart.dpatch: If D-BUS is not available, start on runlevels 2 to
    5, so that this also works in server environments. (LP: #650893)
  * debian/local/apparmor-profile: Allow access to /usr/local/lib/cups/**.
    (LP: #160092)
  * debian/local/apparmor-profile: Allow reading /usr/local/**, in case
    third-party printer drivers need auxiliary files.
  * debian/local/apparmor-profile: Allow reading /var/run/**. (LP: #659961)
  * ubuntu-upstart.dpatch: Time out after 5 seconds when the local socket
    doesn't get created. Apparently a lot of users disable it in cupsd.conf.
    (LP: #672438)
  * debian/local/filters/pdf-filters/addtocups: Link pdftoijs with $(CXX),
    since it's a C++ program. Fixes FTBFS with gcc 4.5.
  * debian/local/filters/pdf-filters/pdftopdf/Makefile: Explicitly pdftopdf
    with -lz. gcc 4.5 does not automatically link to transitive library
    dependencies any more.
  * drop_unnecessary_dependencies.dpatch: Drop hunk for reduced krb5/gssapi
    linkage. With gcc 4.5, we now need -lkrb5.

  [ Marc Deslauriers ]
  * Add CVE-2010-2941.dpatch: Fix denial of service and possible code execution
    via invalid free. Skip over and reserve unused tags in cups/ipp.{c,h}.
    [CVE-2010-2941]
 -- Martin Pitt <email address hidden> Fri, 12 Nov 2010 11:07:33 +0100

Changed in cups (Ubuntu):
status: Fix Committed → Fix Released
Revision history for this message
Daniel Amendoeira (daniel.amendoeira) wrote :

"Disabling the local socket is pretty evil, ..."

But it's disabled by default on a Ubuntu 10.10 Maverick installation.

I'm sure there must be some reasoning for disabling it, but it causes a (very blatant) regression...
Does anybody know why it was disabled?

Revision history for this message
Daniel Amendoeira (daniel.amendoeira) wrote :

"This bug was fixed in the package cups - 1.4.4-7"

Not yet available in the Maverick updates... from what I could tell, 1.4.4-7 is scheduled for Natty.

It this update going to be pushed back into Maverick?

Revision history for this message
Daniel Amendoeira (daniel.amendoeira) wrote :

"But it's disabled by default on a Ubuntu 10.10 Maverick installation."

Sorry, my bad...

Socket creation is disabled on config used since Dapper... successive upgrades haven't changed it.

Revision history for this message
perpetualrabbit (perpetualrabbit) wrote :

I am running a natty narwhal server (fully updated) and I am trying to set up a cups server. The cupsd process does not start. The cups configuration is unaltered.

`start cups´ hangs forever. `stop cups´ also hangs forever. I can break with ctrl-c and then `stop cups´ succeeds if I run it a second time. So, this bug is not fixed.

I altered some lines in the /etc/init/cups.conf file. The post-start script looks like this now:

post-start script
    # wait until daemon is ready
    timeout=10
echo $timeout >> /tmp/TEST
    while [ ! -e /var/run/cups/cups.sock ]; do
        sleep 0.5
        timeout=$((${timeout} -1))
echo $timeout >> /tmp/TEST
        if [ "$timeout" -eq 0 ]; then
            echo "cupsd failed to create /var/run/cups/cups.sock, skipping automatic printer configuration" >&2
echo in the if statement >> /tmp/TEST
            exit 0
        fi
    done
echo after a while... >> /tmp/TEST
    # coldplug USB printers
    if type udevadm > /dev/null 2>&1 && [ -x /lib/udev/udev-configure-printer ]; then
        for printer in `udevadm trigger --verbose --dry-run --subsystem-match=usb \
                --attr-match=bInterfaceClass=07 --attr-match=bInterfaceSubClass=01 2>/dev/null || true; \
                        udevadm trigger --verbose --dry-run --subsystem-match=usb \
                --sysname-match='lp[0-9]*' 2>/dev/null || true`; do
            /lib/udev/udev-configure-printer add "${printer#/sys}"
        done
    fi
end script

The echo statements writing to /tmp/TEST are my additions. After running start cups, waiting half a minute, /tmp/TEST contains the following:

10
9
8
7
6
5
4
3
2
1
0
in the if statement
10
9
8
7
6
5
4
3
2
1
0

So, it never arrives at the "echo after a while..." line I added, but the post-start script seems to get executed again and again.

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

@perpetualrabbit: It's not supposed to arrive at "after a while.." due to the "exit 0", at least not if you disabled the local socket. Is that what you did?

I added debugging like this:

post-start script
    exec 2>/tmp/log <----------- add this line
    set -x <----------- and this
    # wait until daemon is ready
[...]

In the "normal" case I get
+ timeout=10
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=9
+ [ 9 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ type udevadm

I. e. it starts up after 0.5 seconds and the loop terminates. If I change the name of cups.sock to force it to fail, "sudo start cups" properly terminates after 5 seconds, and /tmp/log has:

+ timeout=10
+ [ ! -e /var/run/cups/cups.sockxx ]
+ sleep 0.5
+ timeout=9
+ [ 9 -eq 0 ]
[...]
+ [ 1 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sockxx ]
+ sleep 0.5
+ timeout=0
+ [ 0 -eq 0 ]
+ echo cupsd failed to create /var/run/cups/cups.sock, skipping automatic printer configuration
cupsd failed to create /var/run/cups/cups.sock, skipping automatic printer configuration
+ exit 0

So things still work fine for me. They certainly did when I wrote that loop.

@James Hunt: Do you have an idea why post-start gets re-executed after an exit 0?

Revision history for this message
perpetualrabbit (perpetualrabbit) wrote :

@Martin Pitt,

I did some more debugging. What I did is try to move a working cups config from a redhat server to a new ubuntu natty server. So I stopped cups, renamed the ubuntu /etc/cups to /etc/cups.ubuntu. The new config dir was /etc/cups.lorentz, and I made a symlink /etc/cups->/etc/cups.ubuntu. This is when start cups quits working, and starts looping in /etc/init/cups.conf. It loops through the entire script by the way (pre-start, post-start and possibly also exec cupsd -f), not just the post-start. The cups.lorentz config also has a Listen /var/run/cups/cups.sock line, so that is not the problem. I think that it has to do with apparmor not liking a link instead of a directory at /etc/cups, or something like that.

When I just rename the /etc/cups.lorentz directory to /etc/cups (removing the link first), start cups suddenly works.

With the link in place, start cups just keeps looping, which is a bug. It should either just work or give me some apparmor complaint if links to config files or directories are not OK. If it is an apparmor issue, replacing config files/dirs by links is likely a problem for other services as well, like ldap, nfs, fstab etc.

I thought there was one obvious bug in your loop in /etc/init/cups.conf: you forgot a $ in the arithmetic expansion.
Your line is: timeout=$((timeout-1))
   which I thought would never work, and it should be something like this:
     timeout=$((${timeout}-1))
But. I just checked and it seems your line actually _does_ work. Even with the missing $. I can't find that feature in the bash man page.

Revision history for this message
perpetualrabbit (perpetualrabbit) wrote :

@Martin Pitt

I realize my last post could be more clear. What I meant to say is I often make a number of test configs for some service I'm working on. They are in, say, /etc/config.1 /etc/config.2 /etc/config.3. I then switch between them by making a link /etc/config to one of them. This is what I did with cups as well, but apparmor seems to forbid it. Which I think is a bug or at least a undocumented behaviour.

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

perpetualrabbit,

indeed this looks unrelated to the upstart job. The problem with /etc/cups symlinks is that if you have one, cupsd seems to die immediately, and then upstart tries to start it again:

$ ls -ld /etc/cups*
lrwxrwxrwx 1 root root 9 2011-05-25 10:13 /etc/cups -> cups.real
drwxr-xr-x 4 root lp 4096 2011-05-25 10:00 /etc/cups.real

$ sudo strace cupsd -f
[...]
open("/etc/cups/cupsd.conf", O_RDONLY) = -1 EACCES (Permission denied)
socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 4
connect(4, {sa_family=AF_FILE, path="/dev/log"}, 110) = -1 ECONNREFUSED (Connection refused)
close(4) = 0
exit_group(1) = ?

Now, I have no immediate idea why cupsd would get an EACCESS error on opening /etc/cups/cupsd.conf, I can even run it as non-root just fine:

$ head -n1 /etc/cups/cupsd.conf
LogLevel warn

So this should be reported as a separate bug, preferably right at http://cups.org/str.php. Thanks!

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

Duplicates of this bug

Other bug subscribers

Remote bug watches

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