Bug ID 1029021
Summary foomatic-rip gs fail launching hpijs (probably usb issue)?
Classification openSUSE
Product openSUSE Distribution
Version Leap 42.2
Hardware 64bit
OS openSUSE 42.2
Status NEW
Severity Major
Priority P5 - None
Component Printing
Assignee jsmeix@suse.com
Reporter diego.ercolani@gmail.com
QA Contact jsmeix@suse.com
Found By ---
Blocker --- 

Created attachment 717133 [details]
log and debug information of hpijs "unworking"

I have a personal HP OfficeJet Pro k550.
I would like to use hpijs driver but printing with cups fail.

This is the USB bus:

Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 006 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 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 018: ID 03f0:1812 Hewlett-Packard OfficeJet Pro K550
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 003: ID 0a81:0205 Chesen Electronics Corp. PS/2 Keyboard+Mouse
Adapter
Bus 004 Device 002: ID 0403:6001 Future Technology Devices International, Ltd
FT232 USB-Serial (UART) IC
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub


examining the strace output (file a.log) [strace -f -s 4096 -p `pidof cupsd`]
It seem that the ghostscript fails while trying to communicate to the k550
printer via the USB device. (process 29224 line 14736 of a.log)

I have also some lines in the journal syslog:
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 427: Found interface
conf=0, iface=0, altset=0, index=1
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 389: Active kernel driver
on interface=0 ret=0
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 535: claimed 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 779: read actual
device_id successfully fd=1 len=208
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 427: Found interface
conf=0, iface=0, altset=0, index=1
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 389: Active kernel driver
on interface=0 ret=0
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 535: claimed 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 779: read actual
device_id successfully fd=1 len=208
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 427: Found interface
conf=0, iface=0, altset=0, index=1
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 389: Active kernel driver
on interface=0 ret=0
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 535: claimed 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 816: read actual
device_status successfully fd=1
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 427: Found interface
conf=0, iface=0, altset=0, index=1
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 389: Active kernel driver
on interface=0 ret=0
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 535: claimed 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 779: read actual
device_id successfully fd=1 len=208
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 427: Found interface
conf=0, iface=0, altset=0, index=1
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 389: Active kernel driver
on interface=0 ret=0
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 535: claimed 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 779: read actual
device_id successfully fd=1 len=208
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 427: Found interface
conf=0, iface=0, altset=0, index=1
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 389: Active kernel driver
on interface=0 ret=0
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 535: claimed 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 779: read actual
device_id successfully fd=1 len=208
Mar 11 22:52:13 storage hpijs[29224]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:13 storage hpijs[29224]: prnt/hpijs/hpijs.cpp 647: unable to open
PrintContext object err=2
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 427: Found interface conf=0,
iface=0, altset=0, index=1
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 389: Active kernel driver on
interface=0 ret=0
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 779: read actual device_id
successfully fd=1 len=208
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 959: new PRINT channel=2
clientCnt=1 channelCnt=1
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 427: Found interface conf=0,
iface=0, altset=0, index=1
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 389: Active kernel driver on
interface=0 ret=0
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Mar 11 22:52:13 storage hp[29214]: io/hpmud/musb.c 779: read actual device_id
successfully fd=1 len=208
Mar 11 22:52:15 storage hp[29214]: io/hpmud/musb.c 779: read actual device_id
successfully fd=1 len=208
Mar 11 22:52:17 storage hp[29214]: io/hpmud/musb.c 779: read actual device_id
successfully fd=1 len=208
Mar 11 22:52:19 storage hp[29214]: io/hpmud/musb.c 779: read actual device_id
successfully fd=1 len=208
Mar 11 22:52:21 storage systemd-coredump[29226]: Process 29220 (gs) of user 4
dumped core.
Mar 11 22:52:21 storage hp[29214]: io/hpmud/musb.c 779: read actual device_id
successfully fd=1 len=208
Mar 11 22:52:23 storage hp[29214]: io/hpmud/musb.c 779: read actual device_id
successfully fd=1 len=208
Mar 11 22:52:23 storage hp[29214]: io/hpmud/musb.c 561: released 7/1/2
interface
Mar 11 22:52:23 storage hp[29214]: io/hpmud/musb.c 974: removed PRINT channel=2
clientCnt=0 channelCnt=0

I searched in internet for the same issue but I found non documented like this
issue so probably it appear only in some contest.

by the way: It don't seem a problem of rights of the user lp which is used by
cups

P: /devices/pci0000:00/0000:00:12.2/usb1/1-4
N: bus/usb/001/018
E: BUSNUM=001
E: DEVNAME=/dev/bus/usb/001/018
E: DEVNUM=018
E: DEVPATH=/devices/pci0000:00/0000:00:12.2/usb1/1-4
E: DEVTYPE=usb_device
E: DRIVER=usb
E: ID_BUS=usb
E: ID_FOR_SEAT=usb-pci-0000_00_12_2-usb-0_4
E: ID_HPLIP=1
E: ID_MODEL=Officejet_Pro_K550
E: ID_MODEL_ENC=Officejet\x20Pro\x20K550
E: ID_MODEL_FROM_DATABASE=OfficeJet Pro K550
E: ID_MODEL_ID=1812
E: ID_PATH=pci-0000:00:12.2-usb-0:4
E: ID_PATH_TAG=pci-0000_00_12_2-usb-0_4
E: ID_REVISION=0200
E: ID_SERIAL=HP_Officejet_Pro_K550_MY5BA210B5
E: ID_SERIAL_SHORT=MY5BA210B5
E: ID_USB_INTERFACES=:070102:
E: ID_VENDOR=HP
E: ID_VENDOR_ENC=HP
E: ID_VENDOR_FROM_DATABASE=Hewlett-Packard
E: ID_VENDOR_ID=03f0
E: MAJOR=189
E: MINOR=17
E: PRODUCT=3f0/1812/200
E: SUBSYSTEM=usb
E: SYSTEMD_WANTS=configure-printer@usb-001-018.service printer.target
E: TAGS=:uaccess:seat:systemd:
E: TYPE=0/0/0
E: USEC_INITIALIZED=242301609567
E: hp_test=yes
E: libsane_matched=yes

P: /devices/pci0000:00/0000:00:12.2/usb1/1-4/1-4:1.0
E: DEVPATH=/devices/pci0000:00/0000:00:12.2/usb1/1-4/1-4:1.0
E: DEVTYPE=usb_interface
E: ID_MODEL_FROM_DATABASE=OfficeJet Pro K550
E: ID_VENDOR_FROM_DATABASE=Hewlett-Packard
E: INTERFACE=7/1/2
E: MODALIAS=usb:v03F0p1812d0200dc00dsc00dp00ic07isc01ip02in00
E: PRODUCT=3f0/1812/200
E: SUBSYSTEM=usb
E: TYPE=0/0/0
E: USEC_INITIALIZED=242302805950

storage:/tmp # getfacl /dev/bus/usb/001/018
getfacl: Removing leading '/' from absolute path names
# file: dev/bus/usb/001/018
# owner: root
# group: lp
user::rw-
user:diego:rw-
group::rw-
mask::rw-
other::r--

You are receiving this mail because: