# Yet another "USB printer won't print" plea for advice

## dufeu

I've been struggling with trying to get any usb printer to print on my primary, gentoo based workstation. So far, all my efforts have failed.

In my attempts at resolution, I have been reading quite a few postings regarding usb printer problems. This is what I've found out so far:

1) Assuming I've read various posts and bug reports correctly, starting with CUPS 1.4.0, kernel module usblp is no longer used. As such, CUPS is now using a different approach for that functionality. Some people were able to resolve their usb printing problem by blacklisting that kernel module. That doesn't seem to apply to my situation.

2) Also in CUPS 1.4.0, there was a bug reported in CUPS where EOF was not seen properly at the end of a print job. This would cause an infinite loop condition evidenced by a "Waiting for printer to become available" message and hung print job. This is allegedly resolved with CUPS 1.4.2. I have cups-1.4.2-r1 installed.

3) There is a udev rules issue with multi-function printers. This results in the udev created printer device being 'owned' by the wrong group. This results in error messages:

```
D [28/Dec/2009:00:46:00 -0500] [Job 54] usb_find_busses=0

D [28/Dec/2009:00:46:00 -0500] [Job 54] usb_find_devices=0

D [28/Dec/2009:00:46:00 -0500] [Job 54] STATE: +connecting-to-device

D [28/Dec/2009:00:46:00 -0500] cupsdMarkDirty(-----S)

D [28/Dec/2009:00:46:00 -0500] [Job 54] Failed to set configuration 1 for 04a9:1712

D [28/Dec/2009:00:46:00 -0500] [Job 54] Failed to claim interface 1 for 04a9:1712: Operation not permitted
```

This can be temporarily resolved with:

```
pyrodyno cups # lsusb

Bus 001 Device 002: ID 04a9:1712 Canon, Inc. MP530

Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 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 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

pyrodyno cups # ls -l /dev/bus/usb/001/002

crw-rw-r-- 1 root scanner 189, 1 Dec 27 18:09 /dev/bus/usb/001/002

pyrodyno cups # chgrp lp /dev/bus/usb/001/002

pyrodyno cups # ls -l /dev/bus/usb/001/002

crw-rw-r-- 1 root lp 189, 1 Dec 27 18:09 /dev/bus/usb/001/002
```

As you can see, for this particular printer, the incorrect group ownership is set for this device.

However, once I change the group ownership, I still do not get any output at the printer. These are the messages I get after I change the ownership:

```
D [28/Dec/2009:01:06:15 -0500] [Job 56] Result of putting.

D [28/Dec/2009:01:06:15 -0500] [Job 56] true

D [28/Dec/2009:01:06:15 -0500] [Job 56] -device-

D [28/Dec/2009:01:06:15 -0500] [Job 56] null

D [28/Dec/2009:01:06:15 -0500] [Job 56] -dict-

D [28/Dec/2009:01:06:15 -0500] [Job 56] -save-

D [28/Dec/2009:01:06:15 -0500] [Job 56] Error: /undefined in ESPwl

D [28/Dec/2009:01:06:15 -0500] [Job 56] Operand stack:

D [28/Dec/2009:01:06:15 -0500] [Job 56] 

D [28/Dec/2009:01:06:15 -0500] [Job 56] Execution stack:

D [28/Dec/2009:01:06:15 -0500] [Job 56] %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1862   1   3   %oparray_pop   1861   1   3   %oparray_pop   1845   1   3   %oparray_pop   1739   1   3   %oparray_pop   --nostringval--   %errorexec_pop   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--

D [28/Dec/2009:01:06:15 -0500] [Job 56] Dictionary stack:

D [28/Dec/2009:01:06:15 -0500] [Job 56] --dict:1156/1684(ro)(G)--   --dict:0/20(G)--   --dict:72/200(L)--

D [28/Dec/2009:01:06:15 -0500] [Job 56] Current allocation mode is local

D [28/Dec/2009:01:06:15 -0500] [Job 56] Last OS error: 2

D [28/Dec/2009:01:06:15 -0500] [Job 56] GPL Ghostscript 8.70: Unrecoverable error, exit code 1

D [28/Dec/2009:01:06:15 -0500] [Job 56] Gutenprint: About to start printing loop.

D [28/Dec/2009:01:06:15 -0500] [Job 56] Gutenprint: Printed total 0 bytes
```

Other posts I've read indicate that there isn't actually a problem with "pstorastor". Rather, there is still a problem with accessing the usb based device. Because said device can't be properly accessed, pstorastor can't do it's thing and fails. How true this is, I have no idea. That's just what I've gleaned from reading many google searches.

My thought for this device is that udev should be setting three devices. One for the printer, one for the fax and one for the scanner. If you look at the verbose version of "lsusb" for this device, there are 3 "bNumInterfaces" listed:

```
Bus 001 Device 002: ID 04a9:1712 Canon, Inc. MP530

Device Descriptor:

  bLength                18

  bDescriptorType         1

  bcdUSB               2.00

  bDeviceClass            0 (Defined at Interface level)

  bDeviceSubClass         0 

  bDeviceProtocol         0 

  bMaxPacketSize0        64

  idVendor           0x04a9 Canon, Inc.

  idProduct          0x1712 MP530

  bcdDevice            1.09

  iManufacturer           1 Canon

  iProduct                2 MP530

  iSerial                 3 226935

  bNumConfigurations      1

  Configuration Descriptor:

    bLength                 9

    bDescriptorType         2

    wTotalLength           85

    bNumInterfaces          3

    bConfigurationValue     1

    iConfiguration          0 

    bmAttributes         0xc0

      Self Powered

    MaxPower                2mA

    Interface Descriptor:

      bLength                 9

      bDescriptorType         4

      bInterfaceNumber        0

      bAlternateSetting       0

      bNumEndpoints           3

      bInterfaceClass       255 Vendor Specific Class

      bInterfaceSubClass      0 

      bInterfaceProtocol    255 

      iInterface              0 

      Endpoint Descriptor:

        bLength                 7

        bDescriptorType         5

        bEndpointAddress     0x07  EP 7 OUT

        bmAttributes            2

          Transfer Type            Bulk

          Synch Type               None

          Usage Type               Data

        wMaxPacketSize     0x0200  1x 512 bytes

        bInterval               0

      Endpoint Descriptor:

        bLength                 7

        bDescriptorType         5

        bEndpointAddress     0x88  EP 8 IN

        bmAttributes            2

          Transfer Type            Bulk

          Synch Type               None

          Usage Type               Data

        wMaxPacketSize     0x0200  1x 512 bytes

        bInterval               0

      Endpoint Descriptor:

        bLength                 7

        bDescriptorType         5

        bEndpointAddress     0x89  EP 9 IN

        bmAttributes            3

          Transfer Type            Interrupt

          Synch Type               None

          Usage Type               Data

        wMaxPacketSize     0x0040  1x 64 bytes

        bInterval              11

    Interface Descriptor:

      bLength                 9

      bDescriptorType         4

      bInterfaceNumber        1

      bAlternateSetting       0

      bNumEndpoints           2

      bInterfaceClass         7 Printer

      bInterfaceSubClass      1 Printer

      bInterfaceProtocol      2 Bidirectional

      iInterface              0 

      Endpoint Descriptor:

        bLength                 7

        bDescriptorType         5

        bEndpointAddress     0x01  EP 1 OUT

        bmAttributes            2

          Transfer Type            Bulk

          Synch Type               None

          Usage Type               Data

        wMaxPacketSize     0x0200  1x 512 bytes

        bInterval               0

      Endpoint Descriptor:

        bLength                 7

        bDescriptorType         5

        bEndpointAddress     0x82  EP 2 IN

        bmAttributes            2

          Transfer Type            Bulk

          Synch Type               None

          Usage Type               Data

        wMaxPacketSize     0x0200  1x 512 bytes

        bInterval               0

    Interface Descriptor:

      bLength                 9

      bDescriptorType         4

      bInterfaceNumber        2

      bAlternateSetting       0

      bNumEndpoints           2

      bInterfaceClass         7 Printer

      bInterfaceSubClass      1 Printer

      bInterfaceProtocol      2 Bidirectional

      iInterface              0 

      Endpoint Descriptor:

        bLength                 7

        bDescriptorType         5

        bEndpointAddress     0x0a  EP 10 OUT

        bmAttributes            2

          Transfer Type            Bulk

          Synch Type               None

          Usage Type               Data

        wMaxPacketSize     0x0200  1x 512 bytes

        bInterval               0

      Endpoint Descriptor:

        bLength                 7

        bDescriptorType         5

        bEndpointAddress     0x8b  EP 11 IN

        bmAttributes            2

          Transfer Type            Bulk

          Synch Type               None

          Usage Type               Data

        wMaxPacketSize     0x0200  1x 512 bytes

        bInterval               0

Device Qualifier (for other device speed):

  bLength                10

  bDescriptorType         6

  bcdUSB               2.00

  bDeviceClass            0 (Defined at Interface level)

  bDeviceSubClass         0 

  bDeviceProtocol         0 

  bMaxPacketSize0        64

  bNumConfigurations      1

Device Status:     0x0001

  Self Powered
```

They are interfaces 0, 1 and 2. It looks like interface 0 is the scanner, interfaces 1 and 2 are the printer and the fax, but I can't tell which is which.

 In actuality, only two /dev/usb entries are created. These are /dev/usb/lp0 and /dev/usb/lp1. And indeed, under the Printers applet, there are two printers created: MP530 and MP530-FAX.

The following might help clarify this some more:

```
pyrodyno src # ls -l /dev/bus/usb/001/001

crw-rw-r-- 1 root usb 189, 0 Dec 28 00:15 /dev/bus/usb/001/001

pyrodyno src # ls -l /dev/bus/usb/001/002

crw-rw-r-- 1 root lp 189, 1 Dec 28 00:15 /dev/bus/usb/001/002

pyrodyno src # ls -l /dev/usblp* 

lrwxrwxrwx 1 root root 7 Dec 27 18:09 /dev/usblp0 -> usb/lp0

lrwxrwxrwx 1 root root 7 Dec 27 18:09 /dev/usblp1 -> usb/lp1

pyrodyno src # ls -l /dev/usb   

total 0

crw-rw---- 1 root lp 180, 0 Dec 27 18:09 lp0

crw-rw---- 1 root lp 180, 1 Dec 27 18:09 lp1
```

I'm going to really go out on a limb and make some wild guesses as to what this all means. The problem is that I'm not a programmer and I haven't a clue as to what to determine what's really happening, how to describe it and who to report it to. If anyone has some cogent advice, I'd appreciate it.

I'm guessing that udev is correctly creating /dev entries. That indeed, /dev/bus/usb/001/002 should indeed belong to group "scanner". The problem appears to be that part of the CUPS system is correctly identifying the two output devices and these are being correctly created when I plug the printer in but that when output actually takes place, it's being sent to the scanner interface.

I'm further guessing that the general problem that people are seeing with some usb based printers is one where the printer is correctly identified but output is being directed to the usb controller in the printer, not to the actual output interface in the printer. 

Currently, I can't print to either of the usb based printers I have. With both printers, I get an indication that the print job is printing but nothing appears. In addition to the Canon Prixma MP530 noted above, I have also tried printing with an HP Deskjet D2460. This is a simple print only printer.

I will further point out that I have no problem at all printing to both printers using my LinuxMint {gloria} based netbook using CUPS 1.3.X. Temporarily, my workaround has been to print to postcript files and then transfer them for printing using the netbook.

In the meantime, I'm looking into downgrading CUPS. Given all the inter-related packages, this should be fun.

----------

## dufeu

Downgrading to cups-1.3.11-r2 did not enable me to print.

The error messages are slightly different:

```
D [28/Dec/2009:02:36:30 -0500] [Job 58] Error: /undefined in ESPwl

D [28/Dec/2009:02:36:30 -0500] [Job 58] Operand stack:

D [28/Dec/2009:02:36:30 -0500] [Job 58] 

D [28/Dec/2009:02:36:30 -0500] [Job 58] Execution stack:

D [28/Dec/2009:02:36:30 -0500] [Job 58] %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1862   1   3   %oparray_pop   1861   1   3   %oparray_pop   1845   1   3   %oparray_pop   1739   1   3   %oparray_pop   --nostringval--   %errorexec_pop   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--

D [28/Dec/2009:02:36:30 -0500] [Job 58] Dictionary stack:

D [28/Dec/2009:02:36:30 -0500] [Job 58] --dict:1156/1684(ro)(G)--   --dict:0/20(G)--   --dict:72/200(L)--

D [28/Dec/2009:02:36:30 -0500] [Job 58] Current allocation mode is local

D [28/Dec/2009:02:36:30 -0500] [Job 58] Last OS error: 2

D [28/Dec/2009:02:36:30 -0500] [Job 58] GPL Ghostscript 8.70: Unrecoverable error, exit code 1

E [28/Dec/2009:02:36:30 -0500] PID 4020 (/usr/libexec/cups/filter/pstoraster) stopped with status 1!

D [28/Dec/2009:02:36:30 -0500] [Job 58] Gutenprint: About to start printing loop.

D [28/Dec/2009:02:36:30 -0500] [Job 58] Gutenprint: Printed total 0 bytes

D [28/Dec/2009:02:36:30 -0500] [Job 58] Gutenprint: Used 0.100 seconds user, 0.000 seconds system, 0.411 seconds elapsed

D [28/Dec/2009:02:36:30 -0500] PID 4022 (/usr/libexec/cups/backend/hal) exited with no errors.

D [28/Dec/2009:02:36:30 -0500] PID 4021 (/usr/libexec/cups/filter/rastertogutenprint.5.2) exited with no errors.

D [28/Dec/2009:02:36:30 -0500] [Job 58] File 0 is complete.

E [28/Dec/2009:02:36:30 -0500] [Job 58] Job stopped due to filter errors.
```

```
pyrodyno ~ # ls -l /dev/bus/usb/001/002

crw-rw-r-- 1 root scanner 189, 1 Dec 28 02:25 /dev/bus/usb/001/002

pyrodyno ~ # ls -l /dev/usb            

total 0

crw-rw---- 1 root lp 180, 0 Dec 28 02:25 lp0

crw-rw---- 1 root lp 180, 1 Dec 28 02:25 lp1

pyrodyno ~ # ls -l /dev/usblp*

lrwxrwxrwx 1 root root 7 Dec 28 02:25 /dev/usblp0 -> usb/lp0

lrwxrwxrwx 1 root root 7 Dec 28 02:25 /dev/usblp1 -> usb/lp1

pyrodyno ~ # lpstat

PIXMA-MP500-57          root            231424   Mon Dec 28 02:27:32 2009

pyrodyno ~ # lpstat -a

PIXMA-MP500 accepting requests since Mon Dec 28 02:27:33 2009

pyrodyno ~ # lpstat -t

scheduler is running

no system default destination

device for PIXMA-MP500: hal:///org/freedesktop/Hal/devices/usb_device_4a9_1712_226935_if1_printer_noserial

PIXMA-MP500 accepting requests since Mon Dec 28 02:27:33 2009

printer PIXMA-MP500 is idle.  enabled since Mon Dec 28 02:27:33 2009

   /usr/libexec/cups/filter/pstoraster failed

PIXMA-MP500-57          root            231424   Mon Dec 28 02:27:32 2009

pyrodyno ~ # chgrp lp /dev/bus/usb/001/002

pyrodyno ~ # ls -l /dev/bus/usb/001/002

crw-rw-r-- 1 root lp 189, 1 Dec 28 02:25 /dev/bus/usb/001/002

pyrodyno ~ # lpstat -t

scheduler is running

no system default destination

device for PIXMA-MP500: hal:///org/freedesktop/Hal/devices/usb_device_4a9_1712_226935_if1_printer_noserial

PIXMA-MP500 accepting requests since Mon Dec 28 02:36:30 2009

printer PIXMA-MP500 is idle.  enabled since Mon Dec 28 02:36:30 2009

   /usr/libexec/cups/filter/pstoraster failed

PIXMA-MP500-58          root            231424   Mon Dec 28 02:36:30 2009

pyrodyno ~ # 
```

But the end result is no output.

----------

## kernelOfTruth

*) for me blacklisting the usblp kernel module actually never really worked so I re-compiled my kernel with that module unselected and started to work "better" (it didn't really work yet),

*) also make sure you're updating udev to some newer version above 145 (I don't know the exact version when needed changes for cups 1.4 were incorporated but I'm sure it would be best to unmask or accept_keywords 149 to be on the safe side and then run etc-update)

*) also "modify" printer under the administration "tab" / pull-down menu and change from the former

e.g. 	usb://Brother/HL-2070N%20series to usb://Brother/HL-2070N%20series?serial=A7J778903 or something comparable for the Canon or HP printers 

hope that helps

good luck !

----------

## dufeu

 *kernelOfTruth wrote:*   

> *) for me blacklisting the usblp kernel module actually never really worked so I re-compiled my kernel with that module unselected and started to work "better" (it didn't really work yet)

 

Haven't gone this far yet but certainly intend to look further into kernel settings. Specifically into USB settings. i.e. I'll start by stripping down everything in the usb subsystem to to absolute minimum and work up from there. As far as the kernel goes, there isn't much more that I can do.

I see I didn't make it clear what rev of packages I'm running. My bad!

This is the relevant information:

```
pyrodyno ~ # emerge -pv udev cups hal binutils coreutils cups-pdf gutenprint ghostscript-gpl

These are the packages that would be merged, in order:

Calculating dependencies... done!

[ebuild   R   ] sys-devel/binutils-2.19.1-r1  USE="nls -gold -multislot -multitarget -test -vanilla" 0 kB

[ebuild   R   ] sys-apps/coreutils-8.2  USE="acl gmp nls -caps (-selinux) -static -vanilla -xattr" 0 kB  

[ebuild   R   ] sys-fs/udev-149  USE="devfs-compat extras (-selinux) -test" 0 kB                         

[ebuild   R   ] sys-apps/hal-0.5.14  USE="X acpi consolekit crypt policykit -apm -debug -dell -disk-partition -doc -laptop (-selinux)" 0 kB                                                                                                                               

[ebuild   R   ] net-print/cups-1.4.2-r1  USE="X acl dbus gnutls java jpeg kerberos ldap pam perl php png python samba ssl tiff -debug -slp -static -xinetd" LINGUAS="-da -de -es -eu -fi -fr -it -ja -ko -nl -no -pl -pt -pt_BR -ru -sv -zh -zh_TW" 0 kB                  

[ebuild   R   ] app-text/ghostscript-gpl-8.70-r1  USE="X cairo cups djvu gtk jpeg2k -bindist" LINGUAS="-ja -ko -zh_CN -zh_TW" 0 kB   

[ebuild   R   ] net-print/cups-pdf-2.5.0  0 kB                                                                                       

[ebuild   R   ] net-print/gutenprint-5.2.4  USE="cups foomaticdb gimp gtk ppds readline" 0 kB                                        

Total: 8 packages (8 reinstalls), Size of downloads: 0 kB

pyrodyno ~ # emerge --info

Portage 2.2_rc61 (default/linux/amd64/10.0, gcc-4.4.2, glibc-2.11-r1, 2.6.30.10 x86_64)

=================================================================                      

System uname: Linux-2.6.30.10-x86_64-AMD_Phenom-tm-_9600_Quad-Core_Processor-with-gentoo-2.0.1

Timestamp of tree: Tue, 29 Dec 2009 12:30:01 +0000                                            

ccache version 2.4 [enabled]                                                                  

app-shells/bash:     4.0_p35                                                                  

dev-java/java-config: 2.1.10

dev-lang/python:     2.5.4-r3, 2.6.4, 3.1.1-r1

dev-util/ccache:     2.4-r8

dev-util/cmake:      2.8.0

sys-apps/baselayout: 2.0.1

sys-apps/openrc:     0.6.0

sys-apps/sandbox:    2.2

sys-devel/autoconf:  2.13, 2.65

sys-devel/automake:  1.8.5-r3, 1.9.6-r2, 1.10.3, 1.11.1

sys-devel/binutils:  2.19.1-r1

sys-devel/gcc-config: 1.4.1

sys-devel/libtool:   2.2.6b

virtual/os-headers:  2.6.30-r1

ACCEPT_KEYWORDS="amd64 ~amd64"

ACCEPT_LICENSE="* -@EULA dlj-1.1"

CBUILD="x86_64-pc-linux-gnu"

CFLAGS="-march=opteron -O2 -pipe"

CHOST="x86_64-pc-linux-gnu"
```

As you can see, I've gone back to cups-1.4.

At this point, the best I can figure is that the problem has to do with the usb subsystem. So I'm going to play with kernel settings there.

Thank you for replying. It is appreciated.

----------

## Martux

I just want to thank you. Your thread helped me to solve a old problem of mine  :Smile: 

Finally my parents are able to print again! (I did a downgrade of cups and masked all higher versions.)

Kudos dufeu, hope you´ll fix this too  :Wink: 

----------

## frossie

Okay, for the interest of those doing internet searches out there, I too have solved the same problem (everything looks fine but the printer does not print with "Waiting for printer to become available") by downgrading from cups 1.4.4 to 1.3.11-r2 and re-adding the printer to cups. Note that mine is a simple (single-function) device. 

I'll try and get all my log files together and file this as a bug, since it clearly has been going on long enough.

----------

## Decibels

Thanks Frossie for filing the bug report: https://bugs.gentoo.org/show_bug.cgi?id=326569

I have the same problem you do with a amd64 system and HP LaserJet 1022 using the foo2zjs driver.

Downgrading back to cups-1.3.11-r2 was the only way to get a working printer again. Just decided to look for a bug today cause figured this thing might go stable and it isn't. Thanks for your proactive work!

----------

## trepanne

Sorry to revive a stale thread, but I fixed this same problem on an HP LaserJet 1000, which uses the foo2zjs driver:

http://foo2zjs.rkkda.com/forum/read.php?12,2808

The fix for me was USE="-usb" net-print/cups, which cleared up the conflict.  Absolutely don't blacklist usblp, which is needed to load the firmware onto this wacky printer.

----------

