cups (1.5.0-8ubuntu6) upgrade to precise fails: invoke-rc.d: initscript cups, action "start" failed

[Wookey]

Upgrading from oneiric to precise (with apt-get upgrade) dies on cups:

Setting up cups (1.5.0-8ubuntu6) ...
start: Job failed to start
invoke-rc.d: initscript cups, action "start" failed.
dpkg: error processing cups (--configure):
 subprocess installed post-installation script returned error exit status 1

Using pitti's debug script (as suggested in other similar bugs such as https://bugs.launchpad.net/ubuntu/+source/cups/+bug/979877):

# cp /cups.upstart.debug /etc/init/cups.conf
root@e102475-lin:~# stop cups
stop: Unknown instance:
root@e102475-lin:~# start cups
[waited here for about 2 mins, /tmp/log seemed to be continualy changing in legnth, eventually hit ctrl-C]
^C
root@e102475-lin:~# stop cups
cups stop/waiting

Resulting file:
+ [ -x /usr/sbin/cupsd ]
+ [ -r /etc/default/cups ]
+ . /etc/default/cups
+ LOAD_LP_MODULE=yes
+ [ yes = yes -a -f /usr/lib/cups/backend/parallel -a -f /proc/modules -a -x /sbin/modprobe ]
+ modprobe -q -b lp
+ modprobe -q -b ppdev
+ modprobe -q -b parport_pc
+ mkdir -p /var/run/cups/certs
+ [ -x /lib/init/apparmor-profile-load ]
+ /lib/init/apparmor-profile-load usr.sbin.cupsd
+ timeout=10
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=9
+ [ 9 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=8
+ [ 8 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=7
+ [ 7 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=6
+ [ 6 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=5
+ [ 5 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=4
+ [ 4 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=3
+ [ 3 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=2
+ [ 2 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ sleep 0.5
+ timeout=1
+ [ 1 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock
+ 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

It keeps generating that output over and over until I hit ctrlC. Clearly /var/run/cups/cups.sock is not being created.

ProblemType: Bug
DistroRelease: Ubuntu 12.04
Package: cups 1.5.0-8ubuntu6
ProcVersionSignature: Ubuntu 3.0.0-13.22-generic 3.0.6
Uname: Linux 3.0.0-13-generic x86_64
ApportVersion: 1.23-0ubuntu4
Architecture: amd64
Date: Tue May 8 16:11:19 2012
MachineType: LENOVO 7484WUL
Papersize: a4
PpdFiles:
 biot: HP LaserJet 4100 Foomatic/hpijs
 mougins: HP LaserJet 4100 Foomatic/hpijs
 PDF: Generic CUPS-PDF Printer
 cam-fse-ps: HP LaserJet 8150 Series Postscript (recommended)
ProcEnviron:
 PATH=(custom, no user)
 LANG=en_GB.UTF-8
 SHELL=/bin/bash
ProcKernelCmdLine: BOOT_IMAGE=/vmlinuz-3.0.0-13-generic root=/dev/mapper/vg_root-lv_root ro crashkernel=384M-2G:64M,2G-:128M quiet splash vt.handoff=7
SourcePackage: cups
UdevDb: Error: [Errno 2] No such file or directory
UpgradeStatus: Upgraded to precise on 2011-11-09 (180 days ago)
dmi.bios.date: 02/01/2010
dmi.bios.vendor: LENOVO
dmi.bios.version: 5CKT61AUS
dmi.board.name: LENOVO
dmi.board.vendor: LENOVO
dmi.board.version: NONE
dmi.chassis.asset.tag: �������������������������
dmi.chassis.type: 3
dmi.chassis.vendor: LENOVO
dmi.chassis.version: NONE
dmi.modalias: dmi:bvnLENOVO:bvr5CKT61AUS:bd02/01/2010:svnLENOVO:pn7484WUL:pvrThinkCentreM58p:rvnLENOVO:rnLENOVO:rvrNONE:cvnLENOVO:ct3:cvrNONE:
dmi.product.name: 7484WUL
dmi.product.version: ThinkCentre M58p
dmi.sys.vendor: LENOVO
mtime.conffile..etc.cups.cupsd.conf: 2011-10-12T13:03:15
mtime.conffile..etc.init.cups.conf: 2012-05-08T16:05:06

[Wookey (wookey)]

After running
#stop cups
I still have cups running:
# ps aux | grep cups
root 1039 0.0 0.0 67848 1676 ? Ss Mar22 9:35 /usr/sbin/cupsd -F

If I just add the debug stuff to the normal script I get this:
# start cups
start: Job failed to start

+ sleep 0.5
+ timeout=1
+ [ 1 -eq 0 ]
+ [ ! -e /var/run/cups/cups.sock ]
+ 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

BUt if the exit is zero why does dpkg --configure get 'start failed'?

If I manually kill 1039 then run
#start cups
it works as expected.

So the actual problem here is that stop cups is failing to kill the cups job. I don't know how to debug that, and the state has gone now and no doubt wil be hard to reproduce. Thge pid file pointing to it was there:
# more /var/run/cups/cupsd.pid
1039

Why would upstart fail to follow that and use it?

[Wookey (wookey)]

Oops, I had an apt::defaultrelease oneiric in place so that wasn't actually an upgrade to precise - just pre-precise oneiric updates.

Still, it was definitely poorly...

[Launchpad Janitor (janitor)]

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