Bug 174961

Created attachment 121825 [details]
dmesg output

Also flaky with FC3, FC4.

Looks like a bad cable or a hub, or the printer. The -110 is a timeout,
so a packet is lost. The -71 happens when the firmware in the printer crashes,
but that can be caused by the recovery action of foo2zjs, so it's a secondary
issue.

The http://foo2zjs.rkkda.com/ may be an issue, if we start talking about
firmware downloads, etc. But most likely it's just the a piece hardware somewhere.

No hub.  Tried new cable, 3ft length.  Same problem.  

usb 1-7: new high speed USB device using ehci_hcd and address 34
drivers/usb/class/usblp.c: usblp0: USB Bidirectional printer dev 34 if 0 alt 0
proto 2 vid 0x03F0 pid 0x2B17
drivers/usb/class/usblp.c: usblp0: failed reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
etc..

Also, tried on one FC3 machine, and two FC4 machines.

I still don't expect a problem in software to crop up like that.
This is an isolated report.

I would try forcing the 12 mbit/s speed with an old USB 1.1 hub.

rmmod ehci_hcd and got this:

usb 2-4: new full speed USB device using ohci_hcd and address 4
drivers/usb/class/usblp.c: usblp0: USB Bidirectional printer dev 4 if 0 alt 0
proto 2 vid 0x03F0 pid 0x2B17
drivers/usb/class/usblp.c: usblp0: failed reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status

Any word on this?  There are now approximately ~10 machines that have the problem.

So, let's rule out the hardware for now (if those 10 systems used 10 different
physical printers).

I suppose I can look at a usbmon trace, but honestly, what do you expect
me to do? This is something that only a foo2zjs hacker can understand.

The usblp is too simple. If it says that there was a timeout, that's what
it was.

Oh waaaait a second. You _are_ the foo2zjs hacker. :-)
That helps a little, in the way that perhaps you should tell me
what is happening with the status reading on that thing.

How about that... Certainly, you should have a test bed somewhere, which
runs a recent stock kernel (2.6.14). If that works, let's get usbmon traces
on it and on Fedora, then compare them.

The usbmon howto is installed with kernel-doc rpm,
 /usr/share/doc/kernel-doc-2.6.14/Documentation/usb/usbmon.txt

Created attachment 122671 [details]
usbmon test case #1

This test case #1 had one message:

Jan  1 05:56:19 amd kernel: drivers/usb/class/usblp.c: usblp0: failed reading
printer status

# uname -a
Linux amd.rkkda.org 2.6.12-1.1381_FC3 #1 Fri Oct 21 03:57:59 EDT 2005 x86_64
x86_64 x86_64 GNU/Linux

#1 wasn't good. Probably wrong bus number, there's no printer traffic in it.
Please try to get me one on FC4, or better yet, Rawhide (Rawhide has a better
usbmon - it shows control packets).

T:  Bus=01 Lev=01 Prnt=01 Port=06 Cnt=02 Dev#=  6 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=03f0 ProdID=2b17 Rev= 1.00
S:  Manufacturer=Hewlett-Packard
S:  Product=HP LaserJet 1020
S:  SerialNumber=CNBK944212
C:* #Ifs= 1 Cfg#= 1 Atr=c0 MxPwr= 98mA
I:  If#= 0 Alt= 0 #EPs= 2 Cls=07(print) Sub=01 Prot=02 Driver=usblp
E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=81(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms

# cat /sys/kernel/debug/usbmon/1t > /tmp/1.mon.out

Perhaps there is some other class, not printer?  Or 1s instead of 1t?  The
docu didn't say.

Couldn't get it on FC4.  Modprobe doesn't find usbmon.

[root@localhost ~]# mount -t debugfs none_debugs /sys/kernel/debug
[root@localhost ~]# modprobe usbmon
bash: modprobe: command not found
[root@localhost ~]# /sbin/modprobe usbmon
FATAL: Module usbmon not found.
[root@localhost ~]# uname -a
Linux localhost.localdomain 2.6.14-1.1653_FC4 #1 Tue Dec 13 21:32:09 EST 2005
i686 i686 i386 GNU/Linux
[root@localhost ~]#

I see that it is on bus 1 in comment #15, but there was no printer traffic,
just storage, as if it had a CD-ROM or something.

On FC4, USB core is built statically into the kernel. Look into
/sys/kernel/debug/usbmon, you'll see it there.

Created attachment 122678 [details]
usbmon test #2

T:  Bus=01 Lev=01 Prnt=01 Port=02 Cnt=01 Dev#= 17 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=03f0 ProdID=2b17 Rev= 1.00
S:  Manufacturer=Hewlett-Packard
S:  Product=HP LaserJet 1020
S:  SerialNumber=CNBK944212
C:* #Ifs= 1 Cfg#= 1 Atr=c0 MxPwr= 98mA
I:  If#= 0 Alt= 0 #EPs= 2 Cls=07(print) Sub=01 Prot=02 Driver=usblp
E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=81(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms

[root@localhost ~]# uname -a
Linux localhost.localdomain 2.6.14-1.1653_FC4 #1 Tue Dec 13 21:32:09 EST 2005
i686 i686 i386 GNU/Linux

Jan  1 17:47:39 localhost kernel: drivers/usb/class/usblp.c: usblp0: failed
reading printer status

Hmm.  There is one more problem that FC4 has that FC3 doesn't have.  It involves
"udev".  Should I file another bug report or keep it here?   Basically, firmware
download under FC4 is successfull if I do it manually.  But not if I do it
automaticly via /etc/udev/rules.d/11-hplj10xx.rules.  I get:

# usb_printerid /dev/usb/lp0
Error: Input/output error: GET_DEVICE_ID on '/dev/usb/lp0'

The comment #18 is a perfect trace, and shows a strange problem...
Something is trying to read from a write endpoint:
dc0a2a80 1388765875 S Bi:017:01 -115 8192 <

No, wait, I take it back. The direction bit is not set and the printer has two
endpoints with the same address (01).

So, we see that the request to get status times out, which is what produces
the printk. Then, we have firmware downloaded fine (at least the printer accepts
the data stream). Then, the read URB ends with -ENOENT, which is an unlink.
So, the status times out before the firmware is downloaded.

About comment #19, firstly it is not the same scenario as captured, because
it we were getting status and not ID, as here. As for udev, I do not see how
it could affect it. It often fails to create device nodes, so you cannot
even open /dev/usb/lp0, but this is not what you printed after "I get:"!

Would you mind stop meandering from problem to problem and get an error
scenario nailed down? So far I saw no evidence of any kernel problem.

Well, 10 people have the problem - which is "flaky".  Of those emailed me. 
Another group has no problem.  I will file another bug on #19.

Based on #20, If I do this completely manaully, there is no problem.

# usb_printerid /dev/usb/lp0
# cp /usr/share/foo2zjs/firmware/sihp1020.dl /dev/usb/lp0
# usb_printerid /dev/usb/lp0
# foo2zjs -r600x600 -P -z1 testpage.ps > /dev/usb/lp0

And no "failed reading ..." in dmesg.  This trace is stored in usbmon test #3.

This should be equivalent to CUPS.  But it is not.  When CUPS does it we get:

localhost kernel: drivers/usb/class/usblp.c: usblp0: failed reading printer status

Created attachment 122695 [details]
usbmon test #3

This is a mass-update to all currently open kernel bugs.

A new kernel update has been released (Version: 2.6.15-1.1830_FC4)
based upon a new upstream kernel release.

Please retest against this new kernel, as a large number of patches
go into each upstream release, possibly including changes that
may address this problem.

This bug has been placed in NEEDINFO_REPORTER state.
Due to the large volume of inactive bugs in bugzilla, if this bug is
still in this state in two weeks time, it will be closed.

Should this bug still be relevant after this period, the reporter
can reopen the bug at any time. Any other users on the Cc: list
of this bug can request that the bug be reopened by adding a
comment to the bug.

If this bug is a problem preventing you from installing the
release this version is filed against, please see bug 169613.

Thank you.

Same problem.

[rick@localhost ~]$ uname -a
Linux localhost.localdomain 2.6.15-1.1830_FC4 #1 Thu Feb 2 17:23:41 EST 2006
i686 i686 i386 GNU/Linux

[rick@localhost ~]$ dmesg
drivers/usb/class/usblp.c: usblp0: failed reading printer status

Have the same problem with this printer. It worked when I tried it for the first
time, after that, printing doesn't work anymore with the error messages you
described. Any news concerning this bug?

Hello there,
I'm the one who has made the printer going the first time. The problem to me
seems very simple, the printer does not respond to an ioctl status request. As
cups is doing this every once in a while the error message comes out. (In fact I
had to modify the usb_printerid program to skip checking for the printer status).
I might be wrong but it seems that the status check is done by some ACL Language.
Also I'd check the new HP driver with the new firmware, which I had no time to
test, but they probably changed something there too.

The situation is, we're at the finger-pointing impasse with Rick.
I have absolutely no clue as to how the 1020 works. He does have, but
he's not willing to translate it into a language I can understand.
I thought that usbmon would clear it, but it doesn't. I still do not
see any misbehaviour on the kernel part. Rick still thinks that kernel
ought to do something differently, and I have no idea what, so I cannot
implement that something.

This was just to confirm that to me it does not concer the kernel, but the
printer and maybe cups. 
I made this printer work on FC1 the migrated to FC3 and FC4 and the problem was
always there, also other users with other distributions reported that this
messages come out (just to discard patches that RadHat adds to the  kernel)
Also note that though the problems is still there the printer is usable, I think
it's a problem in the way the firmware is uploaded. I actually have two versions
of the printer firmware, and the newer one is giving me more troubles than the
older one, that's why I mentioned it before, probably HP changed something,
though Rick is still using the older one.
Also changing to udev gave me some troubles too.

(In reply to comment #25)
> [rick@localhost ~]$ dmesg
> drivers/usb/class/usblp.c: usblp0: failed reading printer status
> 
The same problem was recreated on my Fedora Core 5 machine with the latest
kernel, 2.6.16-1.2080_FC5. The 1020 printer simply does not respond and ain't
accessible in any way.
My dmesg output:

usbcore: registered new driver usblp
drivers/usb/class/usblp.c: v0.13: USB Printer Device Class driver
drivers/usb/class/usblp.c: usblp0: failed reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
usb 3-5: USB disconnect, address 7
drivers/usb/class/usblp.c: usblp0: removed
usb 3-6: new high speed USB device using ehci_hcd and address 8
usb 3-6: configuration #1 chosen from 1 choice
drivers/usb/class/usblp.c: usblp0: USB Bidirectional printer dev 8 if 0 alt 0
proto 2 vid 0x03F0 pid 0x2B17
ppdev0: registered pardevice
ppdev0: unregistered pardevice
ppdev1: claim the port first
ppdev2: claim the port first
ppdev3: claim the port first
drivers/usb/class/usblp.c: usblp0: failed reading printer status
drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
ppdev0: registered pardevice
ppdev0: unregistered pardevice
ppdev1: claim the port first
ppdev2: claim the port first
ppdev3: claim the port first
drivers/usb/class/usblp.c: usblp0: failed reading printer status
 

I have tried some usblp hacks, including increasing the timeout and adding this
printer to the "unidirectional" exception list in usblp.c.  Neither of these
helped...

My printer sometimes works reliably for a day, then fails for weeks :(

Newer foo2zjs & cups appear to have the option to run a usblp equivalent in
userspace. This works. Just select the other device...

My /var/log/messages still gets a lot of warnings about timeouts, but the
userspace driver seems to just blindly retry and things work.

Jul  8 20:32:15 bree hpiod: unable to read Device::GetDeviceStatus: Connection
timed out hp:/usb/HP_LaserJet_1020?serial=FN15359 io/hpiod/device.cpp 1014
Jul  8 20:32:22 bree hpiod: invalid Device::DeviceStatus: Connection timed out
hp:/usb/HP_LaserJet_1020?serial=FN15359 io/hpiod/device.cpp 751
Jul  8 20:32:22 bree hpiod: unable to read Device::GetDeviceStatus: Connection
timed out hp:/usb/HP_LaserJet_1020?serial=FN15359 io/hpiod/device.cpp 1014
Jul  8 20:32:29 bree hpiod: invalid Device::DeviceStatus: Connection timed out
hp:/usb/HP_LaserJet_1020?serial=FN15359 io/hpiod/device.cpp 751
Jul  8 20:32:29 bree hpiod: unable to read Device::GetDeviceStatus: Connection
timed out hp:/usb/HP_LaserJet_1020?serial=FN15359 io/hpiod/device.cpp 1014
Jul  8 20:32:36 bree hpiod: invalid Device::DeviceStatus: Connection timed out
hp:/usb/HP_LaserJet_1020?serial=FN15359 io/hpiod/device.cpp 751

Of course, that userland program is hpiod, from the hplip RPM...