Why does CUPS break at EVERY update ?!?

**dargaud** · September 6th, 2012

Argh ! I can't stand CUPS anymore. Every upgrade breaks it. And then the next upgrade fixes it without me ever understanding WTF is wrong with it. It's like my 5th call for help in 2 years on this forum.

This time the symptoms are: the 1st page after a reboot prints halfway and stays in the printer while the 'data incoming' LED blinks. Forever. The job status says "Pending [...] Unable to send data to printer."

Doing a service restart doesn't help. I have a huge error_log bug here's the short version:

Code:

$ grep -v -C 5 "^D \|^I " /var/log/cups/error_log 
D [06/Sep/2012:19:29:00 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [06/Sep/2012:19:29:00 +0200] cupsdMarkDirty(P-----)
D [06/Sep/2012:19:29:00 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [06/Sep/2012:19:29:00 +0200] cupsdRegisterPrinter(p=0x7fd0fa7ea150(Stylus-Photo-R1800))
D [06/Sep/2012:19:29:00 +0200] Updating TXT record for EPSON Stylus Photo R1800 @ penguin (_ipp._tcp)
E [06/Sep/2012:19:29:00 +0200] Failed to update TXT record for EPSON Stylus Photo R1800 @ penguin: -2
D [06/Sep/2012:19:29:00 +0200] Registering Avahi printer Stylus-Photo-R1800 with name "EPSON Stylus Photo R1800 @ penguin" and type "_ipp._tcp,_cups,_universal"
D [06/Sep/2012:19:29:00 +0200] Adding TXT record for EPSON Stylus Photo R1800 @ penguin (_ipp._tcp)
D [06/Sep/2012:19:29:00 +0200] Adding TXT record for EPSON Stylus Photo R1800 @ penguin (_cups._sub._ipp._tcp)
D [06/Sep/2012:19:29:00 +0200] Adding TXT record for EPSON Stylus Photo R1800 @ penguin (_universal._sub._ipp._tcp)
D [06/Sep/2012:19:29:00 +0200] cupsdMarkDirty(P-----)
--
D [06/Sep/2012:19:31:00 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [06/Sep/2012:19:31:00 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [06/Sep/2012:19:31:00 +0200] cupsdReadClient: 17 WAITING Closing on EOF
D [06/Sep/2012:19:31:00 +0200] cupsdCloseClient: 17
D [06/Sep/2012:19:31:00 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
E [06/Sep/2012:19:31:00 +0200] [Job 156] Unable to send data to printer.
D [06/Sep/2012:19:31:00 +0200] [Job 156] Set job-printer-state-message to "Unable to send data to printer.", current level=ERROR
D [06/Sep/2012:19:31:00 +0200] [Job 156] libusb write operation returned fffffffc.
D [06/Sep/2012:19:31:00 +0200] [Job 156] Sent 495616 bytes...
D [06/Sep/2012:19:31:00 +0200] cupsdMarkDirty(-----S)
D [06/Sep/2012:19:31:00 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
--
D [06/Sep/2012:19:31:00 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [06/Sep/2012:19:31:00 +0200] cupsdMarkDirty(P-----)
D [06/Sep/2012:19:31:00 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [06/Sep/2012:19:31:00 +0200] cupsdRegisterPrinter(p=0x7fd0fa7ea150(Stylus-Photo-R1800))
D [06/Sep/2012:19:31:00 +0200] Updating TXT record for EPSON Stylus Photo R1800 @ penguin (_ipp._tcp)
E [06/Sep/2012:19:31:00 +0200] Failed to update TXT record for EPSON Stylus Photo R1800 @ penguin: -2
D [06/Sep/2012:19:31:00 +0200] Registering Avahi printer Stylus-Photo-R1800 with name "EPSON Stylus Photo R1800 @ penguin" and type "_ipp._tcp,_cups,_universal"
D [06/Sep/2012:19:31:00 +0200] Adding TXT record for EPSON Stylus Photo R1800 @ penguin (_ipp._tcp)
D [06/Sep/2012:19:31:00 +0200] Adding TXT record for EPSON Stylus Photo R1800 @ penguin (_cups._sub._ipp._tcp)
D [06/Sep/2012:19:31:00 +0200] Adding TXT record for EPSON Stylus Photo R1800 @ penguin (_universal._sub._ipp._tcp)
D [06/Sep/2012:19:31:00 +0200] cupsdMarkDirty(P-----)

**dargaud** · September 7th, 2012

No taker ?
Doing cups restart, reboot, printer on/off and/or driver reinstall doesn't do anything.
One thing I notice is that after the printer gets stuck in the middle of the 1st print, it disapears from lsusb !!!

Printer works fine from a direct USB device in a VirtualBox WinXP.

**dargaud** · September 8th, 2012

Bump again. I've been at it several days and can't find anything useful on the 'net. If I remove the CUPS config and restart from scratch, I get this in the error_log:

Code:

W [08/Sep/2012:12:40:11 +0200] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'EPSON-Stylus_Photo_R1800-Gray..' already exists                                                                                            
W [08/Sep/2012:12:40:11 +0200] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'EPSON-Stylus_Photo_R1800-RGB..' already exists                                                                                             
W [08/Sep/2012:12:40:11 +0200] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-EPSON-Stylus_Photo_R1800' already exists                                                                                                
W [08/Sep/2012:12:40:22 +0200] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'EPSON-Stylus_Photo_R1800-Gray..' already exists
W [08/Sep/2012:12:40:22 +0200] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'EPSON-Stylus_Photo_R1800-RGB..' already exists
W [08/Sep/2012:12:40:22 +0200] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-EPSON-Stylus_Photo_R1800' already exists
W [08/Sep/2012:12:40:22 +0200] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'EPSON-Stylus_Photo_R1800-Gray..' already exists
W [08/Sep/2012:12:40:22 +0200] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'EPSON-Stylus_Photo_R1800-RGB..' already exists
W [08/Sep/2012:12:40:22 +0200] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-EPSON-Stylus_Photo_R1800' already exists

I wonder if there's some file somewhere that doesn't get removed...

Code:

$ locate freedesktop.Color
/etc/dbus-1/system.d/org.freedesktop.ColorManager.conf
/usr/share/dbus-1/interfaces/org.freedesktop.ColorManager.Device.xml
/usr/share/dbus-1/interfaces/org.freedesktop.ColorManager.Profile.xml
/usr/share/dbus-1/interfaces/org.freedesktop.ColorManager.Sensor.xml
/usr/share/dbus-1/interfaces/org.freedesktop.ColorManager.xml
/usr/share/dbus-1/system-services/org.freedesktop.ColorManager.service

**dargaud** · September 8th, 2012

Here's some more info from the syslog file:

Code:

kernel: [66275.040632] usblp0: removed
kernel: [66275.053294] usblp0: USB Bidirectional printer dev 2 if 0 alt 0 proto 2 vid 0x04B8 pid 0x0007
udev-configure-printer: add /devices/pci0000:00/0000:00:12.2/usb1/1-1/1-1:1.0/usb/lp0
udev-configure-printer: device devpath is /devices/pci0000:00/0000:00:12.2/usb1/1-1
udev-configure-printer: Device already handled
kernel: [66287.352465] usblp0: removed
kernel: [66303.069647] ehci_hcd 0000:00:12.2: force halt; handshake ffffc90000c1c824 00004000 00000000 -> -110
kernel: [66303.069659] ehci_hcd 0000:00:12.2: HC died; cleaning up
kernel: [66303.069678] cannot submit datapipe for urb 1, error -19: no device
kernel: [66303.069726] usb 1-1: USB disconnect, device number 2
kernel: [66303.072869] usb 1-3: USB disconnect, device number 4
udev-configure-printer: remove /devices/pci0000:00/0000:00:12.2/usb1/1-1
udev-configure-printer: URI of print queue: usb://EPSON/Stylus%20Photo%20R1800?serial=RS0070507301426530, normalized: epson stylus photo r1800 serial rs0070507301426530
udev-configure-printer: URI of detected printer: usb://EPSON/Stylus%20Photo%20R1800?serial=RS0070507301426530, normalized: epson stylus photo r1800 serial rs0070507301426530
udev-configure-printer: Queue ipp://localhost:631/printers/EPSON_Stylus_Photo_R1800 has matching device URI
udev-configure-printer: Disabled printer ipp://localhost:631/printers/EPSON_Stylus_Photo_R1800 as the corresponding device was unplugged or turned off
kernel: [66304.072380] timeout: still 1 active urbs..

**dargaud** · September 8th, 2012

Solved ?
I did a simple 'aptitude reinstall cups', deleted and reinstalled the printer and now it works. Go figure...

**kw217** · September 22nd, 2012

Thanks, the reinstall helped my Canon MX300 on Ubuntu 12.04 as well. I had to pick a different name for the printer when I reinstalled though - using the same name meant I still got problems.

--KW

**Artif** · November 17th, 2012

Originally Posted by dargaud

Solved ?
I did a simple 'aptitude reinstall cups', deleted and reinstalled the printer and now it works. Go figure...

Why break at EVERY update? It seems this is a question. Historico-philosophical. Linux and opensource software are permanently floating and unstable. Developers and apologists are sometimes young (no life experience), some times extremely creative persons (huge unstableness). Now days.

CUPS:

Solved? It seems not solved. You just reinstalled CUPS, I reinstalled drivers (one more time, average is 1 per mounth since spring), and it will be workable for some time. Until smth. unknown will happens... Can't catch. May be VNC session related????

It seems it do not depend on drivers. I tried both - third party and "official" - drivers with the same result. The similar problem descriptions could be found for another printers. In one e-mail can be found: it may be related not to Apple, but to opensource community code, have been commited some mounth ago to cups.org, as far as I remeber the URL.

Excuse me, please, for some arraignment and sharp rhetoric.