HP Offficejet 4630 hangs after some time

[zdohnal]

Hi,

we have an issue in Fedora with HP OfficeJet 4630 - the device has IPP-over-USB interface (lsusb -v log), it's recognized by ipp-usb, which creates HTTP reverse proxy at localhost:60000 and advertises it via mDNS, so dialogs with temporary queue support are able to see it and print to it.

However, the device goes deaf after some time - ipp-usb is still running (whole ipp-usb logs). CUPS can connect to localhost:60000 (the proof for ipp-usb is running), the printing goes fine for a time (CUPS log when user printed to the temp queue), but the communication ends after approx. 1 minute.

From main.log we can see the device is added at 17:58:39:

30-03-2022 17:58:39: + HOTPLUG: added Bus 005 Device 001$ 
30-03-2022 17:58:39: + HOTPLUG: added Bus 006 Device 001$ 
30-03-2022 17:58:39: + PNP Bus 003 Device 011: added

then there is a successful print job 221 in cups log:

Mar 30 18:00:57 chargestone-cave cupsd[230955]: [Job 221] Job completed.

Then job 222 comes in, starts to be processed:

Mar 30 18:03:18 chargestone-cave cupsd[230955]: cupsdMarkDirty(---J-)
Mar 30 18:03:18 chargestone-cave cupsd[230955]: cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
Mar 30 18:03:18 chargestone-cave cupsd[230955]: [Job 222] File of type application/pdf queued by "mcatanzaro".
Mar 30 18:03:18 chargestone-cave cupsd[230955]: [Job 222] Adding end banner page "none".
Mar 30 18:03:18 chargestone-cave cupsd[230955]: copy_banner(con=(nil)[-1], job=0x55edad80f500[222], name="none")

but the job is in processing for nearly 1 minute because of following reason, which is set right after the document is sent (the printer didn't report this reason before):

Mar 30 18:03:20 chargestone-cave cupsd[230955]: [Job 222] printer-state-reasons keyword spool-area-full-report

Then the device/ipp-usb release one USB connection and any IPP communication ceases and it is never brought up again (from 03f0-c611-CN57D6914T05Y0-HP-Officejet-4630-series.log.0.gz):

3283 30-03-2022 18:04:14: < HTTP[071]: POST http://localhost:60000/ipp/print - 200 OK
3284 30-03-2022 18:04:14: < HTTP[071]: HTTP response header:
3285 30-03-2022 18:04:14: <   HTTP/1.1 200 OK
3286 30-03-2022 18:04:14: <   Cache-Control: must-revalidate, max-age=0
3287 30-03-2022 18:04:14: <   Content-Length: 282
3288 30-03-2022 18:04:14: <   Pragma: no-cache
3289 30-03-2022 18:04:14: <   Server: HP HTTP Server; HP Officejet 4630 series - B4L03A; Serial Number: CN57D6914T05Y0; Built:Thu Dec 04, 2014 11:06:46AM          {MYM1FN1449AR}
3290 30-03-2022 18:04:14: <
3291 30-03-2022 18:04:14: < USB[3]: read: wanted 4096 got 282 total 523
3292 30-03-2022 18:04:14: < HTTP[071]: response body: got 282 bytes; EOF
3293 30-03-2022 18:04:14:   USB[3]: connection released, 1 in use: --- ar- --- ---
3294 30-03-2022 18:04:14: < USB[1]: read: wanted 4096 got 0 total 0
3295 30-03-2022 18:04:14: ! USB[1]: zero-size read
3296 30-03-2022 18:04:15: < USB[1]: read: wanted 4096 got 0 total 0
3297 30-03-2022 18:04:15: ! USB[1]: zero-size read

The zero-size read continues to the end of logs.

CUPS log then shows it deletes the temp queue, which is a bug (cupsd shouldn't remove temp queue which is processing...):

Mar 30 18:04:19 chargestone-cave cupsd[230955]: cupsdDeletePrinter(p=0x55edad824db0(HP_Officejet_4630_series_3DF5DF_USB), update=0)

but it happens after the communication ends, so IMO it is not a reason why the communication between ipp-usb and the device ends 5 seconds ago.

Would you mind looking into it? Let me know if you want more data from the user - I've added the links to the latest logs to this github issue as well.

Thank you in advance!

Zdenek

[zdohnal]

We tried keep-alive quirk for http-connection, but without any luck.

[alexpevzner]

Hi Zdenek,

this is what I wanted to suggest first (the keep-alive quirk) but you are faster that me :-)

You need to test http-connection = close as well. Use ipp-usb check to guess the correct device name for quirks.

If nothing helps, I need the entire logs to move forward (all files from /var/log/ipp-usb/* directory)

[zdohnal]

Hi Zdenek,

this is what I wanted to suggest first (the keep-alive quirk) but you are faster that me :-)

You need to test http-connection = close as well.

Ok - I'll pass this to the user, thank you!

Use ipp-usb check to guess the correct device name for quirks.

Thanks! I'll send this to the user and verify myself tomorrow on my Canon printer in the lab.
If it helps me and the user, I'll send PR with update for man page.

If nothing helps, I need the entire logs to move forward (all files from /var/log/ipp-usb/* directory)

Hopefully the third link in the initial comment should contain a .tar.xz archive with all logs from /var/log/ipp-usb.

[zdohnal]

@alexpevzner unfortunately http-connection = close didn't help :( - would you mind looking into it?

[alexpevzner]

Hopefully the third link in the initial comment should contain a .tar.xz archive with all logs from /var/log/ipp-usb.

Sorry, you are not authorized to access attachment #1869581 :-(

[zdohnal]

argh... sorry... I didn't know you need extra permissions for bugzilla attachements... so here we go
cups_log.txt
lsusb.txt
ipp-usb.tar.xz.txt

[zdohnal]

(github should really support other archives than zip...)

[alexpevzner]

Hi Zdenek,

Looking to the black magic passes that Michael Catanzaro has to do, playing around with LibreOffice at one hand and Evince in other hand, I have some impression that the problem may be not on the communication level (i.e., ipp-usb), but with the content of print job sent to device, which can cause firmware to hang.

May be it makes some sense to play a little bit with the PPD file.

I will try to apply more effort to investigate this issue, but will appreciate if you will try to investigate that idea from your side.

BTW, my Kyocera only prints with PPD file, manually extracted from the proprietary driver (it doesn't hang, just prints blank pages).

[zdohnal]

@alexpevzner it seems installing a permanent queue using virtual device from ipp-usb helped, so there can be an issue either in temporary queue mechanism as whole, or in its GTK implementation.

I asked Michael for more logs, so I will leave this opened until I review the logs, if it is okay for you.

[alexpevzner]

OK

[zdohnal]

lp printing via temp queue works fine, so my guess it is an issue with GTK right now.