epson stylus photo r800 fails print after 12.10 Quantal Quetzal upgrade

[Martin Barlow]

I have two laptops with 12.04 which both printed perfectly to epson stylus photo r800. After upgrade, both fail in the same way. The printers are recognised and loaded. But when a print command is sent, or ink level status query via mtink is made, the request never completes. "Processing 17%". Mtink reports error communicating with device after some time.

(REMOVE USB)
Nov 3 22:51:07 flowers kernel: [ 1208.067097] usb 2-2: USB disconnect, device number 2
Nov 3 22:51:07 flowers kernel: [ 1208.067482] usblp0: removed
Nov 3 22:51:07 flowers udev-configure-printer: remove /devices/pci0000:00/0000:00:1d.7/usb2/2-2

(INSERT USB)
Nov 3 22:51:14 flowers kernel: [ 1215.232211] usb 2-2: new high-speed USB device number 4 using ehci_hcd
Nov 3 22:51:14 flowers kernel: [ 1215.393022] usb 2-2: New USB device found, idVendor=04b8, idProduct=0007
Nov 3 22:51:14 flowers kernel: [ 1215.393033] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Nov 3 22:51:14 flowers kernel: [ 1215.393042] usb 2-2: Product: USB2.0 Printer (Hi-speed)
Nov 3 22:51:14 flowers kernel: [ 1215.393049] usb 2-2: Manufacturer: EPSON
Nov 3 22:51:14 flowers kernel: [ 1215.393055] usb 2-2: SerialNumber: HN0100912251742080
Nov 3 22:51:14 flowers kernel: [ 1215.402867] usblp 2-2:1.0: usblp0: USB Bidirectional printer dev 4 if 0 alt 0 proto 2 vid 0x04B8 pid 0x0007
Nov 3 22:51:14 flowers mtp-probe: checking bus 2, device 4: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-2"
Nov 3 22:51:14 flowers mtp-probe: bus: 2, device: 4 was not an MTP device
Nov 3 22:51:14 flowers udev-configure-printer: add /devices/pci0000:00/0000:00:1d.7/usb2/2-2/2-2:1.0
Nov 3 22:51:14 flowers udev-configure-printer: device devpath is /devices/pci0000:00/0000:00:1d.7/usb2/2-2
Nov 3 22:51:14 flowers udev-configure-printer: MFG:EPSON MDL:Stylus Photo R800 SERN:- serial:HN0100912251742080
Nov 3 22:51:15 flowers kernel: [ 1216.543361] usblp0: removed
Nov 3 22:51:15 flowers kernel: [ 1216.565745] usblp 2-2:1.0: usblp0: USB Bidirectional printer dev 4 if 0 alt 0 proto 2 vid 0x04B8 pid 0x0007
Nov 3 22:51:16 flowers udev-configure-printer: URI contains USB serial number
Nov 3 22:51:16 flowers udev-configure-printer: URI match: usb://EPSON/Stylus%20Photo%20R800?serial=HN0100912251742080
Nov 3 22:51:16 flowers udev-configure-printer: URI of detected printer: usb://EPSON/Stylus%20Photo%20R800?serial=HN0100912251742080, normalized: epson stylus photo r800 serial hn0100912251742080
Nov 3 22:51:16 flowers udev-configure-printer: URI of print queue: usb://EPSON/Stylus%20Photo%20R800?serial=HN0100912251742080, normalized: epson stylus photo r800 serial hn0100912251742080
Nov 3 22:51:16 flowers udev-configure-printer: Queue ipp://localhost:631/printers/Stylus-Photo-R800 has matching device URI

lsmod | grep usb
usblp 17892 0
usbhid 46094 0
hid 82340 2 hid_generic,usbhid

lsusb
Bus 002 Device 004: ID 04b8:0007 Seiko Epson Corp. Printer
Bus 002 Device 003: ID 05a9:2640 OmniVision Technologies, Inc. OV2640 Webcam
Bus 003 Device 002: ID 0a5c:4500 Broadcom Corp. BCM2046B1 USB 2.0 Hub (part of BCM2046 Bluetooth)
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 006 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 007 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 003: ID 0a5c:4502 Broadcom Corp. Keyboard (Boot Interface Subclass)
Bus 003 Device 004: ID 0a5c:4503 Broadcom Corp. Mouse (Boot Interface Subclass)

ls -l /dev/usb/lp* /dev/bus/usb/*/*
crw-rw-r-- 1 root root 189, 0 Nov 3 22:31 /dev/bus/usb/001/001
crw-rw-r-- 1 root root 189, 128 Nov 3 22:31 /dev/bus/usb/002/001
crw-rw-r-- 1 root root 189, 130 Nov 3 22:31 /dev/bus/usb/002/003
crw-rw-r-- 1 root lp 189, 131 Nov 3 22:51 /dev/bus/usb/002/004
crw-rw-r-- 1 root root 189, 256 Nov 3 22:31 /dev/bus/usb/003/001
crw-rw-r-- 1 root root 189, 257 Nov 3 22:31 /dev/bus/usb/003/002
crw-rw-r-- 1 root root 189, 258 Nov 3 22:31 /dev/bus/usb/003/003
crw-rw-r-- 1 root root 189, 259 Nov 3 22:31 /dev/bus/usb/003/004
crw-rw-r-- 1 root root 189, 384 Nov 3 22:31 /dev/bus/usb/004/001
crw-rw-r-- 1 root root 189, 512 Nov 3 22:31 /dev/bus/usb/005/001
crw-rw-r-- 1 root root 189, 640 Nov 3 22:31 /dev/bus/usb/006/001
crw-rw-r-- 1 root root 189, 768 Nov 3 22:31 /dev/bus/usb/007/001
crw-rw---- 1 root lp 180, 0 Nov 3 22:51 /dev/usb/lp0

lpinfo -v
network ipp
direct hp
network ipps
network socket
network https
network ipp14
network http
direct usb://EPSON/Stylus%20Photo%20R800?serial=HN0100912251742080
network beh
network lpd
direct hpfax
network smb

dpkg -l | egrep -e "cups|guten" | awk '{ print $2 " "$3 " " $4 }'
bluez-cups 4.101-0ubuntu6 i386
cups 1.6.1-0ubuntu11 i386
cups-bsd 1.6.1-0ubuntu11 i386
cups-client 1.6.1-0ubuntu11 i386
cups-common 1.6.1-0ubuntu11 all
cups-filters 1.0.24-2 i386
cups-ppdc 1.6.1-0ubuntu11 i386
ghostscript-cups 9.06~dfsg-0ubuntu4 i386
gutenprint-locales 5.2.9-1ubuntu1 all
libcups2:i386 1.6.1-0ubuntu11 i386
libcupscgi1:i386 1.6.1-0ubuntu11 i386
libcupsdriver1:i386 1.5.3-0ubuntu4 i386
libcupsfilters1:i386 1.0.24-2 i386
libcupsimage2:i386 1.6.1-0ubuntu11 i386
libcupsmime1:i386 1.6.1-0ubuntu11 i386
libcupsppdc1:i386 1.6.1-0ubuntu11 i386
libgnomecups1.0-1 0.2.3-5ubuntu1 i386
libgutenprint2 5.2.9-1ubuntu1 i386
printer-driver-gutenprint 5.2.9-1ubuntu1 i386
printer-driver-hpcups 3.12.6-3ubuntu4 i386
python-cups 1.9.62-0ubuntu1 i386
python-cupshelpers 1.3.11+20120807-0ubuntu10 all

[Martin Barlow (martin-barlow)]

lsb_release -rd
Description: Ubuntu 12.10
Release: 12.10

[Martin Barlow (martin-barlow)]

I have a smilar issue from logs in

https://answers.launchpad.net/ubuntu/+source/cups/+question/212469

We can see in both issues

[Job X] Printing page 1, Y%

then

[Client Z] Accepted from localhost (Domain)

and then the printing stops.

[Martin Barlow (martin-barlow)]

lsb_release -a; uname -a; apt-cache policy cups
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 12.10
Release: 12.10
Codename: quantal
Linux flowers 3.5.0-17-generic #28-Ubuntu SMP Tue Oct 9 19:32:08 UTC 2012 i686 i686 i686 GNU/Linux
cups:
  Installed: 1.6.1-0ubuntu11
  Candidate: 1.6.1-0ubuntu11
  Version table:
 *** 1.6.1-0ubuntu11 0
        500 http://at.archive.ubuntu.com/ubuntu/ quantal/main i386 Packages
        100 /var/lib/dpkg/status

[Martin Barlow (martin-barlow)]

SO, i noticed that usblp is removed when i print:

Nov 17 23:14:52 salzburg kernel: [ 138.202412] usb 3-2: USB disconnect, device number 2
Nov 17 23:14:52 salzburg kernel: [ 138.202676] usblp0: removed
Nov 17 23:14:52 salzburg udev-configure-printer: remove /devices/pci0000:00/0000:00:14.0/usb3/3-2
Nov 17 23:15:53 salzburg kernel: [ 199.778423] usb 3-2: new high-speed USB device number 3 using xhci_hcd
Nov 17 23:15:53 salzburg kernel: [ 199.827091] usb 3-2: New USB device found, idVendor=04b8, idProduct=0007
Nov 17 23:15:53 salzburg kernel: [ 199.827098] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Nov 17 23:15:53 salzburg kernel: [ 199.827102] usb 3-2: Product: USB2.0 Printer (Hi-speed)
Nov 17 23:15:53 salzburg kernel: [ 199.827105] usb 3-2: Manufacturer: EPSON
Nov 17 23:15:53 salzburg kernel: [ 199.827108] usb 3-2: SerialNumber: HN0100912251742080
Nov 17 23:15:53 salzburg kernel: [ 199.827494] usb 3-2: ep 0x1 - rounding interval to 32768 microframes, ep desc says 0 microframes
Nov 17 23:15:53 salzburg kernel: [ 199.827506] usb 3-2: ep 0x82 - rounding interval to 32768 microframes, ep desc says 0 microframes
Nov 17 23:15:53 salzburg kernel: [ 199.827747] usb 3-2: ep 0x1 - rounding interval to 32768 microframes, ep desc says 0 microframes
Nov 17 23:15:53 salzburg kernel: [ 199.827761] usb 3-2: ep 0x82 - rounding interval to 32768 microframes, ep desc says 0 microframes
Nov 17 23:15:53 salzburg kernel: [ 199.836932] usblp 3-2:1.0: usblp0: USB Bidirectional printer dev 3 if 0 alt 0 proto 2 vid 0x04B8 pid 0x0007
Nov 17 23:15:53 salzburg mtp-probe: checking bus 3, device 3: "/sys/devices/pci0000:00/0000:00:14.0/usb3/3-2"
Nov 17 23:15:53 salzburg mtp-probe: bus: 3, device: 3 was not an MTP device
Nov 17 23:15:53 salzburg udev-configure-printer: add /devices/pci0000:00/0000:00:14.0/usb3/3-2/3-2:1.0
Nov 17 23:15:53 salzburg udev-configure-printer: device devpath is /devices/pci0000:00/0000:00:14.0/usb3/3-2
Nov 17 23:15:53 salzburg udev-configure-printer: MFG:EPSON MDL:Stylus Photo R800 SERN:- serial:HN0100912251742080
Nov 17 23:15:54 salzburg kernel: [ 200.954811] usblp0: removed
Nov 17 23:15:55 salzburg kernel: [ 200.965745] usb 3-2: ep 0x1 - rounding interval to 32768 microframes, ep desc says 0 microframes
Nov 17 23:15:55 salzburg kernel: [ 200.965757] usb 3-2: ep 0x82 - rounding interval to 32768 microframes, ep desc says 0 microframes
Nov 17 23:15:55 salzburg kernel: [ 200.975036] usblp 3-2:1.0: usblp0: USB Bidirectional printer dev 3 if 0 alt 0 proto 2 vid 0x04B8 pid 0x0007
Nov 17 23:15:55 salzburg udev-configure-printer: URI contains USB serial number
Nov 17 23:15:55 salzburg udev-configure-printer: URI match: usb://EPSON/Stylus%20Photo%20R800?serial=HN0100912251742080
Nov 17 23:15:55 salzburg udev-configure-printer: URI of detected printer: usb://EPSON/Stylus%20Photo%20R800?serial=HN0100912251742080, normalized: epson stylus photo r800 serial hn0100912251742080
Nov 17 23:15:55 salzburg udev-configure-printer: Consider also queues with "/usb/lp0" or "/usblp0" in their URIs as matching
Nov 17 23:15:55 salzburg udev-configure-printer: URI of print queue: usb://EPSON/Stylus%20Photo%20R800?serial=HN0100912251...

[Martin Barlow (martin-barlow)]

other errors in cups error log

D [17/Nov/2012:23:26:24 +0100] Calling FindDeviceById(cups-Stylus-Photo-R800)
D [17/Nov/2012:23:26:24 +0100] Calling DeleteDevice(cups-Stylus-Photo-R800)
D [17/Nov/2012:23:26:24 +0100] DeleteDevice failed: org.freedesktop.DBus.Error.InvalidArgs:Type of message, `(s)', does not match expected type `(o)'
D [17/Nov/2012:23:26:25 +0100] Using profile ID "Stylus-Photo-R800-Gray..".
D [17/Nov/2012:23:26:25 +0100] Calling CreateProfile(Stylus-Photo-R800-Gray..,temp)
W [17/Nov/2012:23:26:25 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id 'Stylus-Photo-R800-Gray..' already exists
D [17/Nov/2012:23:26:25 +0100] Using profile ID "Stylus-Photo-R800-RGB..".
D [17/Nov/2012:23:26:25 +0100] Calling CreateProfile(Stylus-Photo-R800-RGB..,temp)
W [17/Nov/2012:23:26:25 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id 'Stylus-Photo-R800-RGB..' already exists
I [17/Nov/2012:23:26:25 +0100] Registering ICC color profiles for "Stylus-Photo-R800".
D [17/Nov/2012:23:26:25 +0100] Calling CreateDevice(cups-Stylus-Photo-R800,temp)
W [17/Nov/2012:23:26:25 +0100] CreateDevice failed: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-Stylus-Photo-R800' already exists

[Martin Barlow (martin-barlow)]

OK, i uploaded cups error log for the print that failed.

This is the one that usblp was removed in syslog

Apparently, blacklisting of usblp is not required in 1.6.X

[Martin Barlow (martin-barlow)]

Bought an HP. moved on.