What were you trying to do that didn't work?

When configuring raw printer queues for zebra printers we see that cups correctly identifies the printer queue as raw and generates a ppd file for the printer. In the rhel 8 version files sent to these queues were passed as plain/text. In rhel 9 we see the addition of the texttopdf filter added to the end of the filter process. This converts the zpl file to pdf which is then sent to the printer. This causes the printer to print a blank page then become disabled.

What is the impact of this issue to you?

Important as this disables printers requiring a manual reboot of the printer. This affect does not happen when sent from a RHEL 8 client.

Please provide the package NVR for which the bug is seen:

cups.x86_64   1:2.3.3op2-16.el9_2.2     @rhel-9-for-x86_64-appstream-eus-rpms

How reproducible is this bug?:

Always from any RHEL 9 client

Steps to reproduce

1. configure raw printer queue for zebra printer on rhel 9 print server
2. use cups browsed on rhel 9 client to find print queue
3. send zpl file to zebra printer through rhel 9 cups client
4. observe that the cups pdf filter is added instead of passing the file as plain.

Expected results

no pdf filters should be added to raw printer queues

Actual results

[gmcnealy@uptime 03952548]$ ./jobinfo guc1sapaiet02-2024-Oct-08-15:47:22/var/log/cups/error_log -j 72
jobinfo 1.00, 3-May-2023

I [08/Oct/2024:15:35:07 +0000] [Job 72] Queued on "ESNAP-NA01" by "ietadm".
I [08/Oct/2024:15:35:07 +0000] [Job 72] File of type text/plain queued by "ietadm".
D [08/Oct/2024:15:35:07 +0000] [Job 72] time-at-processing=1728401707
I [08/Oct/2024:15:35:07 +0000] [Job 72] Started filter /usr/lib/cups/filter/texttopdf (PID 2361721)
I [08/Oct/2024:15:35:07 +0000] [Job 72] Started backend /usr/lib/cups/backend/implicitclass (PID 2361722)
D [08/Oct/2024:15:35:08 +0000] [Job 72] PID 2361721 (/usr/lib/cups/filter/texttopdf) exited with no errors.
D [08/Oct/2024:15:35:08 +0000] [Job 72] gziptoany (PID 2361723) exited with no errors.
D [08/Oct/2024:15:35:08 +0000] [Job 72] Set job-printer-state-message to "gziptoany (PID 2361723) exited with no errors.", current level=INFO
D [08/Oct/2024:15:35:08 +0000] [Job 72] Looking up \"guc1sapucpo1.genmills.com\"...
D [08/Oct/2024:15:35:08 +0000] [Job 72] Connecting to guc1sapucpo1.genmills.com:631
D [08/Oct/2024:15:35:08 +0000] [Job 72] update_reasons(attr=0(), s=\"-cups-certificate-error\")
D [08/Oct/2024:15:35:08 +0000] [Job 72] Connected to 10.62.50.25:631...
D [08/Oct/2024:15:35:08 +0000] [Job 72] Print job accepted - job ID 20.
D [08/Oct/2024:15:35:08 +0000] [Job 72] Waiting for job to complete.
D [08/Oct/2024:15:35:48 +0000] [Job 72] Print file sent.
D [08/Oct/2024:15:35:48 +0000] [Job 72] Print file sent.
D [08/Oct/2024:15:35:49 +0000] [Job 72] Print file sent.
D [08/Oct/2024:15:35:49 +0000] [Job 72] Print file sent.
D [08/Oct/2024:15:35:50 +0000] [Job 72] Print file sent.
D [08/Oct/2024:15:35:50 +0000] [Job 72] Print file sent.
D [08/Oct/2024:15:35:52 +0000] [Job 72] PID 2361722 (/usr/lib/cups/backend/implicitclass) exited with no errors.
D [08/Oct/2024:15:35:52 +0000] [Job 72] time-at-completed=1728401752
I [08/Oct/2024:15:35:52 +0000] [Job 72] Job completed.

Neither the printer or cups report that there were errors with the print job.

// INTERNAL USE ONLY
// DO NOT PUBLISH

> SAP NetWeaver system creating output spool to printer Zebra esnap-na01

File Attachment Created By: Whitelock, Jason at  (10/7/2024 9:12 AM)
> 2024-10-07_sosreport-guc1sapaiet02-2024-10-07-luofhrh.tar (280,683 KB)
> CUPS Client / SAP Application Server
 
File Attachment Created By: Whitelock, Jason at  (10/7/2024 9:12 AM)
> 2024-10-07_sosreport-guc1sapucpo1-2024-10-07-kqfbydm.tar (18,905 KB)
> CUPS Server

SERVER
======

$ qinfo 0030-2024-10-08_sosreport-guc1sapucpo1-2024-10-08-uzfrnif.tar esnap-na01
qinfo 1.03, 22-Sep-2022

=== lpstat for ESNAP-NA01:

    device for ESNAP-NA01: socket://esnap-na01.genmills.com:9100
    ESNAP-NA01 accepting requests since Tue Oct  8 15:35:52 2024
    printer ESNAP-NA01 is idle.  enabled since Tue Oct  8 15:35:52 2024

=== printers.conf entry for ESNAP-NA01:

    <Printer ESNAP-NA01>
    UUID urn:uuid:c0c1ff8e-25e0-307a-7185-1a2c04ee374f
    Info Spain Zebra Printer
    Location San Adrian
    DeviceURI socket://esnap-na01.genmills.com:9100
    State Idle
    StateTime 1728401752
    ConfigTime 1728401601
    Type 4
    Accepting Yes
    Shared Yes
    JobSheets none none
    QuotaPeriod 0
    PageLimit 0
    KLimit 0
    OpPolicy default
    ErrorPolicy retry-job
    </Printer>

=== lpoptions for ESNAP-NA01:

    Dest ESNAP-NA01 raw=true

=== PPD information for ESNAP-NA01:

    RAW Print Queue

=== 2 jobs for ESNAP-NA01 recorded in error_log

    I [08/Oct/2024:15:34:24 +0000] [Job 19] Queued on "ESNAP-NA01" by "ietadm".
    I [08/Oct/2024:15:35:08 +0000] [Job 20] Queued on "ESNAP-NA01" by "ietadm".

=== Printer Configuration Summary

    Queue's Name: ESNAP-NA01
    Printer Type: ??
    Device's URI: socket://esnap-na01.genmills.com:9100
    PPD NickName: RAW

CLIENT (non working)
====================

$ qinfo 0050-2024-10-08_sosreport-guc1sapaiet02-2024-10-08-ankmyag.tar esnap-na01
qinfo 1.03, 22-Sep-2022

=== lpstat for ESNAP-NA01:

    device for ESNAP-NA01: implicitclass://ESNAP-NA01/
    ESNAP-NA01 accepting requests since Tue Oct  8 15:35:52 2024
    printer ESNAP-NA01 is idle.  enabled since Tue Oct  8 15:35:52 2024

=== printers.conf entry for ESNAP-NA01:

    <Printer ESNAP-NA01>
    PrinterId 3570
    UUID urn:uuid:9aa684f9-92bd-313b-787b-ba410c91982e
    AuthInfoRequired none
    Info ESNAP-NA01
    Location 
    MakeModel Local Raw Printer, driverless, cups-filters 1.28.7
    DeviceURI implicitclass://ESNAP-NA01/
    State Idle
    StateTime 1728401752
    ConfigTime 1728401708
    Type 8400990
    Accepting Yes
    Shared No
    JobSheets none none
    QuotaPeriod 0
    PageLimit 0
    KLimit 0
    OpPolicy default
    ErrorPolicy stop-printer
    Option copies 1
    Option cups-browsed true
    Option cups-browsed-dest-printer "72 ipp://guc1sapucpo1.genmills.com:631/printers/ESNAP-NA01 pdf 600dpi"
    Option finishings 0
    Option job-cancel-after 10800
    Option job-hold-until no-hold
    Option job-priority 50
    Option media na_letter_8.5x11in
    Option notify-events job-completed
    Option notify-lease-duration 86400
    Option number-up 1
    Option orientation-requested 0
    Option output-bin face-down
    Option print-color-mode color
    Option print-quality 0
    Option printer-resolution 300x300dpi
    Option sides one-sided
    </Printer>

=== No print options defined for ESNAP-NA01

=== PPD information for ESNAP-NA01:

    *NickName: "Local Raw Printer, driverless, cups-filters 1.28.7"
    *cupsFilter2: "application/pdf application/pdf 0 -"
    *cupsFilter2: "application/vnd.cups-postscript application/postscript 500 -"
    *cupsFilter2: "image/jpeg image/jpeg 0 -"
    *cupsFilter2: "image/png image/png 0 -"
    *cupsFilter2: "application/vnd.cups-pdf application/pdf 0 -"

=== 2 jobs for ESNAP-NA01 recorded in error_log

    I [08/Oct/2024:14:58:46 +0000] [Job 71] Queued on "ESNAP-NA01" by "ietadm".
    I [08/Oct/2024:15:35:07 +0000] [Job 72] Queued on "ESNAP-NA01" by "ietadm".

=== Printer Configuration Summary

    Queue's Name: ESNAP-NA01
    Printer Type: ??
    Device's URI: implicitclass://ESNAP-NA01/
    PPD NickName: "Local Raw Printer, driverless, cups-filters 1.28.7"

$ jobinfo 0050-2024-10-08_sosreport-guc1sapaiet02-2024-10-08-ankmyag.tar/sosreport-guc1sapaiet02-2024-10-08-ankmyag/var/log/cups/error_log -j 71
jobinfo 1.00, 3-May-2023

I [08/Oct/2024:14:58:46 +0000] [Job 71] Queued on "ESNAP-NA01" by "ietadm".
I [08/Oct/2024:14:58:46 +0000] [Job 71] File of type text/plain queued by "ietadm".
D [08/Oct/2024:14:58:46 +0000] [Job 71] time-at-processing=1728399526
I [08/Oct/2024:14:58:46 +0000] [Job 71] Started filter /usr/lib/cups/filter/texttopdf (PID 2352177)
I [08/Oct/2024:14:58:46 +0000] [Job 71] Started backend /usr/lib/cups/backend/implicitclass (PID 2352178)
D [08/Oct/2024:14:58:46 +0000] [Job 71] PID 2352177 (/usr/lib/cups/filter/texttopdf) exited with no errors.
D [08/Oct/2024:14:58:46 +0000] [Job 71] gziptoany (PID 2352179) exited with no errors.
D [08/Oct/2024:14:58:46 +0000] [Job 71] Set job-printer-state-message to "gziptoany (PID 2352179) exited with no errors.", current level=INFO
D [08/Oct/2024:14:58:46 +0000] [Job 71] Looking up \"guc1sapucpo1.genmills.com\"...
D [08/Oct/2024:14:58:46 +0000] [Job 71] Connecting to guc1sapucpo1.genmills.com:631
D [08/Oct/2024:14:58:46 +0000] [Job 71] update_reasons(attr=0(), s=\"-cups-certificate-error\")
D [08/Oct/2024:14:58:46 +0000] [Job 71] Connected to 10.62.50.25:631...
D [08/Oct/2024:14:58:46 +0000] [Job 71] Print job accepted - job ID 18.
D [08/Oct/2024:14:58:46 +0000] [Job 71] Waiting for job to complete.
D [08/Oct/2024:14:59:06 +0000] [Job 71] Print file sent.
D [08/Oct/2024:14:59:06 +0000] [Job 71] Print file sent.
D [08/Oct/2024:14:59:07 +0000] [Job 71] Print file sent.
D [08/Oct/2024:14:59:08 +0000] [Job 71] Print file sent.
D [08/Oct/2024:14:59:08 +0000] [Job 71] Print file sent.
D [08/Oct/2024:14:59:09 +0000] [Job 71] Print file sent.
D [08/Oct/2024:14:59:10 +0000] [Job 71] PID 2352178 (/usr/lib/cups/backend/implicitclass) exited with no errors.
D [08/Oct/2024:14:59:10 +0000] [Job 71] time-at-completed=1728399550
I [08/Oct/2024:14:59:10 +0000] [Job 71] Job completed.

Text (probably actually a ZPL file) is being converted to PDF before being sent to the server, because:

    *cupsFilter2: "application/pdf application/pdf 0 -"
    *cupsFilter2: "application/vnd.cups-postscript application/postscript 500 -"
    *cupsFilter2: "image/jpeg image/jpeg 0 -"
    *cupsFilter2: "image/png image/png 0 -"
    *cupsFilter2: "application/vnd.cups-pdf application/pdf 0 -"

CLIENT (working)
================

$ qinfo 0040-2024-10-08_sosreport-guc1sapaiet03-2024-10-08-qrckdtb.tar esnap-na01
qinfo 1.03, 22-Sep-2022

=== lpstat for ESNAP-NA01:

    device for ESNAP-NA01: implicitclass:ESNAP-NA01
    ESNAP-NA01 accepting requests since Tue Oct  8 15:34:24 2024
    printer ESNAP-NA01 is idle.  enabled since Tue Oct  8 15:34:24 2024

=== printers.conf entry for ESNAP-NA01:

    <Printer ESNAP-NA01>
    UUID urn:uuid:f90cd7f6-4ea4-3093-7718-d89f9784e234
    Info Spain Zebra Printer
    Location San Adrian
    DeviceURI implicitclass:ESNAP-NA01
    State Idle
    StateTime 1728401664
    ConfigTime 1728401663
    Type 4
    Accepting Yes
    Shared Yes
    JobSheets none none
    QuotaPeriod 0
    PageLimit 0
    KLimit 0
    OpPolicy default
    ErrorPolicy stop-printer
    Option copies 1
    Option cups-browsed true
    Option cups-browsed-dest-printer "3 guc1sapucpo1.genmills.com:631/ESNAP-NA01"
    Option finishings 0
    Option job-cancel-after 10800
    Option job-hold-until no-hold
    Option job-priority 50
    Option notify-events job-completed
    Option notify-lease-duration 86400
    Option number-up 1
    Option orientation-requested 0
    Option print-quality 0
    </Printer>

=== No print options defined for ESNAP-NA01

=== PPD information for ESNAP-NA01:

    RAW Print Queue

=== 3 jobs for ESNAP-NA01 recorded in error_log

    I [08/Oct/2024:13:31:24 +0000] [Job 1] Queued on "ESNAP-NA01" by "ietadm".
    I [08/Oct/2024:14:55:31 +0000] [Job 2] Queued on "ESNAP-NA01" by "ietadm".
    I [08/Oct/2024:15:34:23 +0000] [Job 3] Queued on "ESNAP-NA01" by "ietadm".

=== Printer Configuration Summary

    Queue's Name: ESNAP-NA01
    Printer Type: ??
    Device's URI: implicitclass:ESNAP-NA01
    PPD NickName: RAW

So the difference between RHEL 8 and RHEL 9 is that in RHEL 9, cups-browsed is getting IPP attributes from the CUPS server to build it's own PPD file, where as in RHEL 8 (I think), cups-browsed still just downloads and modifies the PPD file from the CUPS server (in this case there is no PPD file to download because the queue is raw on the server).

> There are two interesting bits here and I am sure that a packet
> capture will show more detail as to what is happening here. But the
> interesting parts are:

> 1. Why are there additional filters added to a ppd file for a printer
> configured as 'RAW'?

The "gziptoany" filter is a nothing filter – it just decompresses the file (if it's been compressed).  It doesn't do any kind of data conversion on the file.  The issue is the "texttopdf" filter that's being invoked because the PPD file created by cups-browsed in RHEL 9 includes:

    *cupsFilter2: "application/pdf application/pdf 0 -"
    *cupsFilter2: "application/vnd.cups-postscript application/postscript 500 -"
    *cupsFilter2: "image/jpeg image/jpeg 0 -"
    *cupsFilter2: "image/png image/png 0 -"
    *cupsFilter2: "application/vnd.cups-pdf application/pdf 0 -"

which tells cups that this printer accepts PDF, PostScript, JPG, and PNG files.  Any other file types need to be converted into one of those file types.  The ZPL file is detected as a text file, so it's converted to PDF before being sent to the server.

> 2. Why is the Zebra printer not reporting that the job failed back to
> cups if there is an issue with printing? (according to the customer
> nothing prints)

Because the Zebra printer is just silently ignoring the PDF document that is sent to it.

A quick solution should be to run this on the RHEL 9 client:

    lpadmin -p ESNAP-NA01 -o raw

However, I don't know if this will survive a reboot because I don't know if cups/cups-browsed will save this option when the queue gets removed and re-created when cups-browsed restarts.