implicitclass backend: job cancelled on the printer (job-canceled-by-user, 0 sheets) while CUPS reports the job "completed successfully"

[jordan-dimov]

Environment

• Ubuntu 26.04 (resolute), cups 2.4.16-1ubuntu1.3, cups-browsed 2.1.1-0ubuntu3, libcupsfilters 2.1.1-0ubuntu5, cups-filters 2.0.1-0ubuntu4.1
• Printer: HP OfficeJet 8010 series (product 4KJ69B), Wi-Fi, driverless. DNS-SD TXT: pdl=application/vnd.hp-PCL,image/jpeg,image/urf,image/pwg-raster,application/PCLm; URF=...RS300-600...; qtotal=1; TLS=1.2
• Queue: auto-created by cups-browsed (CreateIPPPrinterQueues default), device-uri implicitclass://HP_OfficeJet_8010_series_666685/, PPD "HP Printer, driverless, 2.1.1". cups-browsed selects "image/urf 600dpi" as the destination format.
• cupsd.conf: ErrorPolicy retry-job, LogLevel warn (default)

Symptom

Printing a 10-page PDF from Firefox (application/pdf, ~500 KB, number-up=2): the printer wakes up, nothing prints, and CUPS shows the job as completed with job-state-reasons=job-completed-successfully and job-media-sheets-completed=10. No error anywhere on the client. The printer's own IPP job log (Get-Jobs which-jobs=completed) shows the same jobs as job-state=canceled, job-state-reasons=job-canceled-by-user, job-media-sheets-completed=0.

Reproduced 4 times out of 5 with the same document via the implicitclass queue (two Firefox submissions, two lp -i N -H restarts). The same PDF through a plain IPP Everywhere queue (lpadmin -p X -E -v ipps://<host>:631/ipp/print -m everywhere) printed 2/2 and honoured page-ranges.

Timeline of one failure (CUPS job 125, printer job 21)

• 23:33:00 Print-Job to CUPS (Firefox)
• 23:33:03 cups-browsed CUPS-Add-Modify-Printer (sets cups-browsed-dest-printer)
• ~23:33:05 job appears on the printer as processing; ~1 s later it is gone
• 23:33:14 CUPS job 125 completed, job-completed-successfully, job-media-sheets-completed=10
• printer: job 21 canceled / job-canceled-by-user / 0 sheets

What the printer does

With one job in progress, a second Print-Job over raw IPP (ipptool) is answered with server-error-busy and printer-state-reasons gains spool-area-full-report (single-job spool, qtotal=1). Verified with two back-to-back ipptool print-job.test runs, no CUPS involved.

Source observations (cups-browsed 2.1.1 backend/implicitclass.c, libcupsfilters 2.1.1 filter.c, cups 2.4.16 backend/ipp.c)

• implicitclass runs cfFilterChain(ppdFilterUniversal -> ppdFilterExternalCUPS("ipp")) and returns CUPS_BACKEND_FAILED only if cfFilterChain returns non-zero; otherwise CUPS_BACKEND_OK.
• backend/ipp.c: in stdin mode (argc==6), if Create-Job/Send-Document returns server-error-busy, service-unavailable or not-possible, the backend calls cancel_job() on the printer and returns CUPS_BACKEND_RETRY_CURRENT; on SIGTERM it cancels the printer job and returns CUPS_BACKEND_OK.
• cfFilterExternal maps any non-zero exit of the child to status 1, so a RETRY_CURRENT from ipp would surface as "Job processing failed" and, with ErrorPolicy retry-job, a retry 30 s later. No retry was observed and the job was marked successful, so the backend process exited 0 despite the printer-side cancel.

Debug-logged reproduction attempts (LogLevel debug)

• small JPEG job, two back to back: both printed (Create-Job / chunked Send-Document / wait; retryable=0)
• small JPEG job to a printer in power save: printed
• 17-page PDF, number-up=2, to a printer in power save: printed (9 sheets)
• 17-page PDF with page-ranges=1: printed 1 sheet (page-ranges honoured)

Under LogLevel debug, and after cups-browsed had been restarted, the failure did not reproduce in 6 attempts. Before that, with cups-browsed running for ~23 h and its queue created at that daemon start, it failed 4 times out of 5 within 2.5 hours (21:30, 23:33, 23:43, 23:46; the success was 23:47). The five runs used the same spool file; the only visible differences were printer state (asleep for three of the four failures, still ejecting the previous page for the fourth).

Why this looks like a backend/chain problem rather than the printer

• The printer accepted Create-Job every time (the job appears on the printer as processing) and then received an explicit Cancel-Job about one second later (HP records that as job-canceled-by-user).
• After the cancel the CUPS job was marked completed / job-completed-successfully with job-media-sheets-completed=10, and no retry happened. With ErrorPolicy retry-job any non-zero backend exit would have produced a retry 30 s later, so the implicitclass process exited 0.
• In backend/ipp.c the only path that both cancels the remote job and returns CUPS_BACKEND_OK is job_canceled>0 (SIGTERM). The busy path (server-error-busy on Send-Document, which this printer does return while its single-job spool is occupied) cancels but returns CUPS_BACKEND_RETRY_CURRENT, which cfFilterExternal/cfFilterChain would turn into "Job processing failed".
• Question for maintainers: is there a way for the ipp child of cfFilterChain to receive SIGTERM (or for its non-zero exit to be lost) while the implicitclass parent still returns CUPS_BACKEND_OK? cups-browsed issues CUPS-Add-Modify-Printer (the cups-browsed-dest-printer option) ~3 s after every job starts; that request carries only a printer option so cupsd should not restart the job, but the timing coincides with the cancels.

Workaround

A permanent IPP Everywhere queue (lpadmin -p HP -E -v ipps://<printer>:631/ipp/print -m everywhere) plus CreateIPPPrinterQueues No in cups-browsed.conf. 4/4 jobs printed through it, including the same document.

Available on request

Printer-side Get-Jobs (which-jobs=completed) output; CUPS job attributes for the failing jobs; LogLevel debug error_log for the six successful runs; the 17-page PDF (238 KB, Microsoft Reporting Services, PDF 1.3, all pages A4).