HP printer not printing in Cooker/znver1

[benbullard79]

OpenMandriva version:
Cooker
Describe the bug:
Printer does not print pages.
Steps to reproduce:
Set up printer in Systemsettings>Printer then select to print test page. Or try to print anything random.
Observed behavior:
Nothing printed.
Expected behavior:
That what user selects to print actually prints.
Additional comment:
Printer is HP Photosmart 6520. Using driver HP Photosmart 6520 series, hpcups. Printer is set up exactly as I do in Rolling and 4.3. In the Systemsettings gui it says "filter failed". Printing from Konsole output:

$ lp /Data1/Documents/Budw.txt
request id is HP_Photosmart_6520_series-14 (1 file(s))

But nothing prints.
Logs and screenshots if relevant

$ rpm -qa | grep cups
lib64cupsfilters1-1.28.15-1.znver1
cups-filters-1.28.15-1.znver1
cups-drivers-lxx74-0.8.4.2-24.znver1
cups-drivers-magicolor2430dl-1.6.1-28.znver1
cups-drivers-magicolor5430dl-1.8.1-29.znver1
cups-drivers-magicolor5440dl-1.2.1-28.znver1
cups-drivers-splix-2.0.0-20.znver1
gutenprint-cups-5.3.4-1.znver1
python-cups-1.9.74-3.znver1
cups-drivers-pegg-0.23-26.znver1
cups-drivers-2008-24.znver1
cups-drivers-foo2zjs-0.20201003-1.znver1
lib64cups2-2.4.1-4.znver1
cups-common-2.4.1-4.znver1
cups-2.4.1-4.znver1
lib64cupsimage2-2.4.1-4.znver1

$ rpm -qa | grep hplip
hplip-hpijs-3.22.4-2.znver1
hplip-hpijs-ppds-3.22.4-2.znver1
hplip-model-data-3.22.4-2.znver1
hplip-gui-3.22.4-2.znver1
hplip-3.22.4-2.znver1

$ systemctl status cups
● cups.service - CUPS Scheduler
     Loaded: loaded (/lib/systemd/system/cups.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2022-06-10 10:22:18 CDT; 6min ago
TriggeredBy: ● cups.path
             ● cups.socket
       Docs: man:cupsd(8)
   Main PID: 1003 (cupsd)
     Status: "Scheduler is running..."
      Tasks: 3 (limit: 38323)
     Memory: 159.3M
     CGroup: /system.slice/cups.service
             ├─ 1003 /usr/sbin/cupsd -l
             └─ 1680 /usr/lib/cups/notifier/dbus dbus://

Jun 10 10:22:18 C-Z-998 systemd[1]: Starting CUPS Scheduler...
Jun 10 10:22:18 C-Z-998 systemd[1]: Started CUPS Scheduler.
Jun 10 10:22:46 C-Z-998 hpcups[1685]: prnt/hpcups/HPCupsFilter.cpp 602: cupsRasterOpen failed, fd = 0
Jun 10 10:22:46 C-Z-998 hp[1686]: prnt/backend/hp.c 913: ERROR: null print job total=0
Jun 10 10:25:34 C-Z-998 hpfax[1871]: [1871]: error: Failed to create /var/spool/cups/tmp/.hplip
Jun 10 10:26:14 C-Z-998 hpcups[1996]: prnt/hpcups/HPCupsFilter.cpp 602: cupsRasterOpen failed, fd = 0
Jun 10 10:26:14 C-Z-998 hp[1997]: prnt/backend/hp.c 913: ERROR: null print job total=0
Jun 10 10:27:31 C-Z-998 hpcups[2138]: prnt/hpcups/HPCupsFilter.cpp 602: cupsRasterOpen failed, fd = 0

$ systemctl status cups.socket
● cups.socket - CUPS Scheduler
     Loaded: loaded (/lib/systemd/system/cups.socket; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2022-06-10 10:22:17 CDT; 56min ago
      Until: Fri 2022-06-10 10:22:17 CDT; 56min ago
   Triggers: ● cups.service
     Listen: /run/cups/cups.sock (Stream)
     CGroup: /system.slice/cups.socket

Jun 10 10:22:17 C-Z-998 systemd[1]: Listening on CUPS Scheduler.

$ systemctl status cups.path
● cups.path - CUPS Scheduler
     Loaded: loaded (/lib/systemd/system/cups.path; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2022-06-10 10:22:17 CDT; 56min ago
      Until: Fri 2022-06-10 10:22:17 CDT; 56min ago
   Triggers: ● cups.service

Jun 10 10:22:17 C-Z-998 systemd[1]: Started CUPS Scheduler.

omdv-bug-report-20220610112250.log

I do not know if this is cups or hplip or something else. Will do what is needed to resolve this issue.

[benbullard79]

Some more information. Printer is connected via usb. This computer is multi-boot with currently partitions containing 4.3, Rolling, and Cooker all znver1.

Printer is also scanner and fax. I never use fax so do not test. I do use printer and scanner (Skanlite).

Printer and scanner work normally on Rolling and 4.3 partitions. Scanner works in Cooker.

[AngryPenguinPL]

Hi. I never add printer directly via cups but only in hplip. I use WIFI auto-detect or manually discovering via WIFI IP adress and my printer HP Photosmart 5524 works fine on Cooker x86_64.

[benbullard79]

Since we are getting close to moving stuff from cooker to rolling thought to check on this bug. Problem remains the same.

I normally add printer with kcmshell5 kcm_printer_manager. My printer presently usb connection though it is wifi capable. This has been standard method in all versions of OM Lx here for a while.

Problem is that it adds the printer but the printer does not print giving the error: Idle -'Filter failed'

Not sure but I think it is this:

Jun 30 15:11:21 C-Z-998 hpcups[3017]: prnt/hpcups/HPCupsFilter.cpp 602: cupsRasterOpen failed, fd = 0

[benbullard79]

Current omdv bug report log for my Cooker desktop.

omdv-bug-report-20220630153632.log

[benbullard79]

Changed title to reflect this is a Cooker/znver1. Discovered today printer is working in Cooker/x86_64 system

Worth noting I only check printing and scanning on hardware systems.

This file may lead to why this problem exists in Cooker/znver1:

hp-check.txt

[benbullard79]

Crap. That hp-check output looks exactly the same in Cooker/x86_64 system where printer is working so it may not be telling anything helpful for this issue.

EDIT: in reality the hp-check thing seem useless from what my limited knowledge can see.

[benbullard79]

This issue persists. Printer installs but does not print. journal shows:

Aug 29 14:41:41 C-Z-XFS-1337 hpcups[20748]: prnt/hpcups/HPCupsFilter.cpp 603: cupsRasterOpen failed, fd = 0
Aug 29 14:41:41 C-Z-XFS-1337 hp[20749]: prnt/backend/hp.c 913: ERROR: null print job total=0

[benbullard79]

This issue got more interesting today. Now I only have the Cooker znver1 system on my desktop. After dsync today when I try to print a test page from kcm_printer_manager or localhost:631 the test page does not print straight away.

But if I reboot the test page prints. There is some output in journal log so I am posting log of last 3 boots.

journalctl-b-2.txt

journalctl-b-1.txt

journalctl-b-0.txt

[benbullard79]

This looks to me like one of the calls to print test page:

Oct 13 10:46:19 C-Z-XFS-1337 plasmashell[7273]: console.warn: LoginRecipes: "Falling back to a synchronous message for: http://localhost:631."
Oct 13 10:46:19 C-Z-XFS-1337 plasmashell[1332]: kf.i18n: 1 instead of 2 arguments to message "Printing %1 with %2" supplied before conversion
Oct 13 10:46:19 C-Z-XFS-1337 plasmashell[1332]: kf.i18n: 1 instead of 2 arguments to message "Printing %1 with %2" supplied before conversion
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 515: invalid claim_interface 7/1/2: Device or resource busy
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=1, index=3
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 515: invalid claim_interface 7/1/4: Device or resource busy
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 427: Found interface conf=0, iface=3, altset=0, index=9
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 389: Active kernel driver on interface=3 ret=0
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 515: invalid claim_interface ff/4/1: Device or resource busy
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=11
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 535: claimed ff/cc/0 interface
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 780: read actual device_id successfully fd=11 len=663
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 561: released ff/cc/0 interface
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 960: new PRINT channel=2 clientCnt=1 channelCnt=1
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 515: invalid claim_interface 7/1/2: Device or resource busy
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 975: removed PRINT channel=2 clientCnt=0 channelCnt=0
Oct 13 10:46:19 C-Z-XFS-1337 hp[7358]: prnt/backend/hp.c 845: INFO: open print channel failed stat=21; will retry in 30 seconds...
Oct 13 10:46:49 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 960: new PRINT channel=2 clientCnt=1 channelCnt=1
Oct 13 10:46:49 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Oct 13 10:46:49 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Oct 13 10:46:49 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 515: invalid claim_interface 7/1/2: Device or resource busy
Oct 13 10:46:49 C-Z-XFS-1337 hp[7358]: io/hpmud/musb.c 975: removed PRINT channel=2 clientCnt=0 channelCnt=0
Oct 13 10:46:49 C-Z-XFS-1337 hp[7358]: prnt/backend/hp.c 845: INFO: open print channel failed stat=21; will retry in 30 seconds...

And this looks to me like what happens when I reboot and the test page prints:

Oct 13 10:22:05 C-Z-XFS-1337 kernel: usblp1: removed
Oct 13 10:22:05 C-Z-XFS-1337 smartd[926]: Device: /dev/sda [SAT], enable SMART Automatic Offline Testing failed.
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 780: read actual device_id successfully fd=1 len=663
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 960: new PRINT channel=2 clientCnt=1 channelCnt=1
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Oct 13 10:22:05 C-Z-XFS-1337 hp[992]: io/hpmud/musb.c 535: claimed 7/1/2 interface

Test page seems to always print right after sddm.service starts. Currently sddm is set to autologin.

[benbullard79]

For now this seems to be fixed by removing usbmuxd and ipp-usb. I think bero is going to rm usbmuxd from default package lists. Not so sure we can do that with ipp-usb. My guess is people in future will need that for "driverless" printing.

I just hope this stays fixed, it has been aggravating as heck.