usb connection failures

[Wolfgang Rosenauer]

Since I'm using openSUSE 11.2 with my HP OfficeJet 6315 I can rarely print w/o issues.
hplip 3.9.8
The relevant log entries look like this:
They look like the connection is lost during communication but I'm not sure if that is caused by software or hardware.
Actually I somehow don't think it's hardware but I also need to check a few things and different USB ports to rule that out. For example scanning works more or less properly as well as other usb communication (sd card reader). Only print jobs are completely broken.

Jan 29 17:12:45 Hygiea hpijs[26516]: io/hpmud/musb.c 594: invalid usb_open: Permission denied
Jan 29 17:12:45 Hygiea kernel: [40984.803810] usblp1: removed
Jan 29 17:12:45 Hygiea hp[26508]: io/hpmud/musb.c 594: invalid usb_open: Permission denied
Jan 29 17:13:16 Hygiea kernel: [41015.797043] usb 1-4: reset high speed USB device using ehci_hcd and address 4
Jan 29 17:13:16 Hygiea kernel: [41015.912794] usblp1: USB Bidirectional printer dev 4 if 1 alt 0 proto 2 vid 0x03F0 pid 0x5311
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1022: bulk_write failed buf=0x7fff556bae50 size=8192 len=-34: Success
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1389: unable to write data hp:/usb/Officejet_6300_series?serial=CN69DCH2GW04M4: Success
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 725: invalid deviceid wIndex=1, retrying wIndex=100: Input/output error
Jan 29 17:13:16 Hygiea kernel: [41015.914175] usb 1-4: usbfs: process 26508 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea kernel: [41015.914262] usb 1-4: usbfs: process 26508 (hp) did not claim interface 0 before use
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1022: bulk_write failed buf=0x7fff556bae50 size=8192 len=-5: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1389: unable to write data hp:/usb/Officejet_6300_series?serial=CN69DCH2GW04M4: Input/output error
Jan 29 17:13:16 Hygiea kernel: [41015.914995] usb 1-4: usbfs: process 26629 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea kernel: [41015.915150] usb 1-4: usbfs: process 26508 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 725: invalid deviceid wIndex=1, retrying wIndex=100: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1022: bulk_write failed buf=0x7fff556bae50 size=8192 len=-5: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1389: unable to write data hp:/usb/Officejet_6300_series?serial=CN69DCH2GW04M4: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 725: invalid deviceid wIndex=1, retrying wIndex=100: Input/output error
Jan 29 17:13:16 Hygiea kernel: [41015.915709] usb 1-4: usbfs: process 26630 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea kernel: [41015.915868] usb 1-4: usbfs: process 26508 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1022: bulk_write failed buf=0x7fff556bae50 size=8192 len=-5: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1389: unable to write data hp:/usb/Officejet_6300_series?serial=CN69DCH2GW04M4: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 725: invalid deviceid wIndex=1, retrying wIndex=100: Input/output error
Jan 29 17:13:16 Hygiea kernel: [41015.916466] usb 1-4: usbfs: process 26631 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea kernel: [41015.916620] usb 1-4: usbfs: process 26508 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea kernel: [41015.917211] usb 1-4: usbfs: process 26632 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1022: bulk_write failed buf=0x7fff556bae50 size=8192 len=-5: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1389: unable to write data hp:/usb/Officejet_6300_series?serial=CN69DCH2GW04M4: Input/output error
Jan 29 17:13:16 Hygiea kernel: [41015.917372] usb 1-4: usbfs: process 26508 (hp) did not claim interface 1 before use
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 725: invalid deviceid wIndex=1, retrying wIndex=100: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1022: bulk_write failed buf=0x7fff556bae50 size=8192 len=-5: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 1389: unable to write data hp:/usb/Officejet_6300_series?serial=CN69DCH2GW04M4: Input/output error
Jan 29 17:13:16 Hygiea hp[26508]: io/hpmud/musb.c 725: invalid deviceid wIndex=1, retrying wIndex=100: Input/output error

[Naga Samrat Chowdary, Narla (samrat-hplip)]

How are you installed HPLIP, is it from Package Manager (or) by downloaded from www.hplipopensource.com?

you are required to resolve the dependencies which are shown in the hp-check output.

su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses cupsddk"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses cups-devel"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses cups-devel"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses openssl"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses libjpeg-devel"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses net-snmp-devel"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses libtool libgphoto2-devel"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses libusb-devel libusb-1_0-0"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses python-imaging"
su -c "zypper --non-interactive --no-gpg-checks in --auto-agree-with-licenses python-devel python-xml"

Hope this Helps,
Naga Samrat Chowdary.

[Wolfgang Rosenauer (wolfgang-rosenauer)]

It's installed straight from openSUSE 11.2.

I checked these requirements again and they are either COMPILE_TIME requirements or OPTIONAL/RUNTIME requirements.

[Johannes Meixner (jsmeix)]

I agree with Wolfgang that none of the "missing" packages
have anything to do with the low-level USB failures which
are reported here.

When the low-level base USB connection is lost during communication,
(i.e. when it is as if the device was unplugged and re-plugged), the
device node file /dev/bus/usb/<bus#>/<device#> becomes re-created
with an increased <device#> and afterwards udev would change its
permissions according to what is specified for the particular
model's USB IDs in /etc/udev/rules.d/55-hpmud.rules
But when while this happens io/hpmud/musb.c (which runs as "lp")
continues to write data to the device a "Permission denied" might
happen.

In contrast whe the "Permission denied" is the initial error,
it looks like a duplicate of
https://bugzilla.novell.com/show_bug.cgi?id=542473
(read it in particular for background information)
and for a workaround see in particular
https://bugzilla.novell.com/show_bug.cgi?id=565950#c1

Another way to get device access "Permission denied" issues
while printing totally out of sight is to run /usr/lib{64]/backend/cups/hp
as root, see the "PERMISSIONS" section in "man backend".

But perhaps the root cause of the USB communication breakage
is that the device seems to be operated as "high speed USB device
using ehci_hcd" but actually the device fails to work reliably
in high speed mode. In this case have a look at
http://bugzilla.novell.com/show_bug.cgi?id=554664#c10

Of course when the "ehci" kernel module is unloaded
all USB devices can only work in lower speed but at least
for a test to find out if the USB speed is the root cause
you should check if printing works reliably in lower USB speed.

I am not at all an USB expert and I don't know if it is possible
to tell the USB system in the kernel to use lower USB speed
only for particular USB devices.

[Naga Samrat Chowdary, Narla (samrat-hplip)]

libusb-devel and libusb-1_0-0 are required to be installed for USB communication.

Thank you for supporting HPLIP,
Naga Samrat Chowdary.

[Wolfgang Rosenauer (wolfgang-rosenauer)]

libusb-1_0-0 obviously is installed. Not sure why it's mentioned in the hp-check output. Probably broken script. Otherwise I would have a hard time to get anything working with usb?

libusb-devel is not installed though and I don't see why a devel package should be needed to run an application.
Anyway I installed it now but don't expect any changes unless we need header files and pkgconfig files to print.

[Johannes Meixner (jsmeix)]

Wolfgang, did you run
  hp-check -r
to test only for run-time requirements?

I guess libusb is mentioned in a plain "hp-check" output
because this tests for both kind of requirements
and the compile-time requirement regarding libusb
is both libusb-devel and libusb.

See the hp-check output or "hp-check -h".

[Wolfgang Rosenauer (wolfgang-rosenauer)]

When I run hp-check -r I only get warnings about
missing cupsddk and python-imaging and in the detailed output they are mentioned as optional

[Johannes Meixner (jsmeix)]

Wolfgang,
are there any news regarding what I wrote above in
https://bugs.launchpad.net/hplip/+bug/519707/comments/4

[Wolfgang Rosenauer (wolfgang-rosenauer)]

Some news. Sorry for the delay but it took a bit to find some time for debugging.
1. I have no *hci modules loaded at all in openSUSE 11.2 so I couldn't remove any
2. I always get permission denied messages when starting a print job but they seem to be not critical:
Apr 16 18:01:38 Hygiea hpijs[16049]: io/hpmud/musb.c 594: invalid usb_open: Permission denied
Apr 16 18:01:38 Hygiea hp[16041]: io/hpmud/musb.c 594: invalid usb_open: Permission denied
but the print job still worked and no more messages were printed after that.
3. I just tried one thing which seemed to help:
   rmmod usblp
I was able to print big printjobs afterwards w/o running into the issue while it usually takes between 1-4 pages to start failing I was able to print many more. I'll just remove that module from now on when I print and will see if I ever get back the issues.

[Johannes Meixner (jsmeix)]

When "rmmod usblp" helps, it looks like a new effect
of the old usblp <-> usbfs/libusb kernel driver conflict, see
https://bugzilla.novell.com/show_bug.cgi?id=184825

I am really no USB expert but I guess that after "rmmod usblp"
even the "io/hpmud/musb.c 594: invalid usb_open: Permission denied"
error messages do no longer happen?

It might happen that an automated "modprobe usblp"
is done every time when the device is connected
to the USB via whatever udev magic - search all
udev rules files in /etc/udev/rules.d/ and
/lib/udev/rules.d/ and /dev/.udev/rules.d/
see "man udev":
----------------------------------------------------------
The udev rules are read from the files located
in the default rules directory /lib/udev/rules.d/,
the custom rules directory /etc/udev/rules.d/
and the temporary rules directory
/dev/.udev/rules.d/
----------------------------------------------------------

[Wolfgang Rosenauer (wolfgang-rosenauer)]

The permission denied messages are still logged with start of any printjob apparently.

I have /etc/udev/rules.d/70-printers.rules:
# Low-level USB device add trigger
ACTION=="add", SUBSYSTEM=="usb", ATTR{bInterfaceClass}=="07", ATTR{bInterfaceSubClass}=="01", RUN+="udev-configure-printer add %p"
# usblp device add trigger (needed when usblp is already loaded)
ACTION=="add", KERNEL=="lp*", RUN+="udev-configure-printer add %p"

# Low-level USB device remove trigger
ACTION=="remove", SUBSYSTEM=="usb", ENV{ID_USB_INTERFACES}=="*:0701*:*", RUN+="udev-configure-printer remove %p"

udev-configure-printer is a binary so not sure what it does (didn't do source code inspection).

Issue didn't happen since I rmmod usblp before every printjob.

[Johannes Meixner (jsmeix)]

"rpm -qi udev-configure-printer" would tell you something like
---------------------------------------------
This package contains an utility that will ensure printers get
automatically configured when plugged on the computer.
---------------------------------------------
and
my famous yast2-printer help text in its "Autoconfig Settings"
dialog would tell you something like
---------------------------------------------
CUPS Autoconfiguration for USB Printers

Autoconfiguration is provided by two RPM packages:
The new 'udev-configure-printer' since openSUSE 11.2 and
the meanwhile deprecated 'cups-autoconfig' because the latter
uses HAL which is deprecated.
...
When udev-configure-printer is used,
automatic USB printer setup happens via the entries
in its udev config file /etc/udev/rules.d/70-printers.rules
which triggers to run 'udev-configure-printer add'
when a USB printer is plugged in
and 'udev-configure-printer remove' when it is unplugged.
There are no settings when udev-configure-printer is used
except one changes the 70-printers.rules file manually.
---------------------------------------------

In the very unlikely case that you do not desperately
need a nowadays full automagic USB printer setup tool
(and that you really are an traditional person who still
perfers to do your printer setup on your own ;-)
you might even dare to remove the udev-configure-printer
package to get unwanted automatisms out of your way,
compare
http://bugzilla.novell.com/show_bug.cgi?id=594812#c1
;-)

For details what exactly udev-configure-printer does,
there is a link to its sources at
https://bugzilla.novell.com/show_bug.cgi?id=594812#c5