implicitclass: too short wait time for printer attributes request

[tthef]

The implicitclass waits for up to 20s for a response from cups-browsed to IPP_OP_GET_PRINTER_ATTRIBUTES but I am seeing that with HP ENVY 7640 series in wifi-direct mode the response takes just over 20s, which then results in cups stopping the printer and 'No destination host name supplied by cups-browsed for printer \"HP_ENVY_7640_seriesE1C883\", is cups-browsed running?' in the error log.

This is a snippet from the log that shows that. The request is dispatched by browsed at 07:45:31 and the response arrives at 07:45:51, by this time the implicitclass backend is already giving up.

07:45:31 2021 [CUPS Notification] HP_ENVY_7640_series_E1C883_ starts processing a job.
07:45:31 2021 [CUPS Notification] HP_ENVY_7640_series_E1C883_ is using the "implicitclass" CUPS backend, so let us search for a destination for this job.
07:45:31 2021 Remote CUPS printers clustered as queue HP_ENVY_7640_series_E1C883_:
07:45:31 2021   ipps://HP%20ENVY%207640%20series%20%5BE1C883%5D._ipps._tcp.local/* (last job printed)
07:45:31 2021 Checking state of remote printer ipps://HP%20ENVY%207640%20series%20%5BE1C883%5D._ipps._tcp.local/ on host HP308D99E1C883.local, IP (null), port 443.
07:45:31 2021 HTTP connection to HP308D99E1C883.local:443 established.

     ^^^ the Request is dispatched immediately after the above ^^^

07:45:51 2021 Requested IPP attributes (get-printer-attributes) for printer with URI ipps://HP308D99E1C883.local:443/ipp/print
    ^^^ the above is printed only after the response arrives ^^^

07:45:51 2021 IPP request to HP308D99E1C883.local:443 successful.
07:45:51 2021 IPP Response contains attributes values printer-name HPE1C883, accepting-job 1

... 07:45:51 2021 [CUPS Notification] Job state changed on printer HP_ENVY_7640_seriesE1C883: Printer stopped due to backend errors; please consult the /var/log/cups/error_log file for details.

Note that this printer works just fine when attached to a local network, but basically running the wifi-direct network on it just bogs it down; I expect there will be host of HP printers suffering from the same problem.

[Bhavna2020]

hi Are you using the newest release of cups-filters? If not, could you please try it or prior you can provide us with the error_log file

[tthef]

Yes, I am using the latest version, and as stated in the original report, the error log shows

E [07:45:51] [Job 2] No destination host name supplied by cups-browsed for printer \"HP_ENVY_7640_seriesE1C883\", is cups-browsed running?

There are no other errors. The 20s policy is implemented at https://github.com/OpenPrinting/cups-filters/blob/master/backend/implicitclass.c#L160.

[Bhavna2020]

Ok. The only problem seems is the cups-browsed. Either you halt its functioning or remove it by using following commands systemctl mask cups-browsed sudo apt-get purge --autoremove cups-browsed

and then add a new printer. hope it works

[tillkamppeter]

@Bhavna2020, you know that implicitclass is a backend of cups-browsed used to manage printing to printer clusters? implicitclass without cups-browsed running never works, you will ALWAYS get the message that no destination got supplied, regardless what is the timeout. So please DO NOT tell the OP to uninstall cups-browsed.

implicitclass works as follows: cups-browsed creates a cluster of several remote printers and for this cluster it creates one local print queue using the implicitclass backend. If the user prints a job on this local queue, the implicitclass backend gets called in order to send the job off to one of the cluster's member printers. To know which printer is the right one for the job it gets help from cups-browsed. cups-browsed gets note of the job by subscribing to CUPS' D-Bus notifications. It then determines which printer the job should go to and adds an attribute/option to the local queue containing all needed information, especially the URI of the destination printer and also the job number for reference.

implicitclass is checking the printer's attributes (currently for up to 20 seconds) until cups-browsed has set said attribute for this job (it checks the job number in the attribute) and then sends the data off to the appropriate destination.

Usually this works, but there can be the following scenarios causing the mentioned error:

• cups-browsed is not running (trivial, make sure it is running)
• cups-browsed is too busy to answer within 20 seconds: This can happen if there are lots of printers in the network and cups-browsed eeds time to create local print queues for all of them. First, try modifying implicitclass to use a longer timeout, see @tthef's comment above. If it does not work, even with crazily long timeouts, the problem is rather the third scenario which I mention below.
• CUPS is not sending D-Bus notifications or cups-browsed is not receiving them.

To investigate, edit /etc/cups/cups-browsed.conf and restart cups-browsed to get debug logging. See in the log file whether cups-browsed receives the job notification, whether it determines the destination, and whether it does this within 20 seconds after the job was submitted.

[tthef]

This issue is about driverless printing using wifi-direct, you don't 'add a new printer', cups-browsed discovers and adds it for you, that's what it is for. This works just fine in general, except the implicitclass driver doesn't allow enough time for communication with the printer to happen in the above scenario. As per the original report, there is likely to be a whole host of printers like that, so the maintainers might want to increase the time the driver waits for the response; that's all this issue is about.

[tthef]

@tillkamppeter the notifications are working, and there are no other printers on the network, but what you see in the log is that it takes just over 20s for the response to arrive from the printer, I suspect even 21s wait would have worked in this case. I don't have direct access to the printer, but I have patched the system to wait 30s, it will take couple of days to retest, but I am quitely optimistic.

BTW, thanks for cups-browsed, it's awesome to be able to print this way.

[tthef]

I can confirm that increasing the wait in implicitclass to 30s makes the HP ENVY 7640 work in wifi-direct mode.

[Bhavna2020]

@tillkamppeter OK.

@tthef the problem may be because cups-browsed requires long time to create print queue with larger ppd file, so have you tried editing the cups-browsed.conf, increasing the Http timeout in your /etc/cups/cups-browsed.conf file as it worked in many cases, reportedly, and then restart the cups-browsed and mention if it worked and the time taken in the debug_log.

[tillkamppeter]

Fixed in pull request #346.

@Bhavna2020, thank you very much.