OpenPrinting / cups

OpenPrinting CUPS Sources
https://openprinting.github.io/cups
Apache License 2.0
1.05k stars 187 forks source link

[2.4.8] Printing short-edge regardless of settings due cupsUrfSupported incorrectly generated #952

Closed HROMANO closed 3 months ago

HROMANO commented 5 months ago

Describe the bug With cups 2.4.8, whatever I choose 'Long edge' or 'Short edge', I get a 'Short Edge' print. When I downgrade to cups 2.4.7, the choices work as usual.

System Information:

Additional context The printer is a network driverless printer (IPPS) Model HP ENVY 6032e

zdohnal commented 4 months ago

Hi,

thank you for reporting the issue!

Would you mind turning on debug logging for CUPS, reproduce the issue and then attach file with logs here?

Thank you in advance!

HROMANO commented 4 months ago

This is /var/log/cups/error.log after enabling debug logging.

The faulty print is [Job 1072], starting at around [17/May/2024:13:14:21 +0200].

error_log

zdohnal commented 4 months ago

Hmm, both app and IPP backend sends the correct option and value - I've tested it with my home printer and Fedora 39 + CUPS 2.4.8, and DuplexNoTumble was applied well...

Is you printer installed as permanent queue? If it is, can you reinstall the queue, and attach its PPD file from /etc/cups/ppd.

@michaelrsweet I don't recall we did something regarding duplex...

michaelrsweet commented 4 months ago

@zdohnal No we haven't touched the duplex handling code in a long time...

HROMANO commented 4 months ago

I'm not sure what you mean with 'permanent queue'. The printer is auto discovered (avahi I suppose) and I didn't installed it specifically.

zdohnal commented 4 months ago

@HROMANO

If you run lpstat -l -e, it lists available destinations, where the second word is the type of installation. The permanent queues are marked permanent, auto discovered/temporary ones are marked as network. Can you shared the output of the command?

HROMANO commented 4 months ago

Yes, it's not a permanent queue:

GARAGE_AIRPRINT network none ipps://GARAGE_AIRPRINT._ipps._tcp.local/
HP_ENVY_6000_series_5493E7 network none ipps://HP%20ENVY%206000%20series%20%5B5493E7%5D._ipps._tcp.local/

(first printer. The second is my wife's printer, same model and same problem).

zdohnal commented 4 months ago

Ok - can you check whether cups-browsed is running and show printer options?

$ systemctl is-active cups-browsed
$ lpoptions -p GARAGE_AIRPRINT -l
$ lpoptions -p GARAGE_AIRPRINT

It would help to see screenshot of problematic and successful printing as well + CUPS debug log for older CUPS.

I hope I can see some difference between them to realize what is the problem, because I don't see the issue on any of my work printers...

HROMANO commented 4 months ago

Here are the first results:

inactive

lpoptions -p GARAGE_AIRPRINT -l

PageSize/Media Size: 100x150mm 100x150mm.Borderless 3.5x5 3.5x5.Borderless 4x6 4x6.Borderless 5x7 5x7.Borderless 5x8 5x8.Borderless 8x10 8x10.Borderless A4 A4.Borderless A5 A5.Borderless A6 A6.Borderless B5 B5.Borderless Env10 EnvC6 EnvChou3 EnvChou4 EnvDL Executive ISOB5 Letter Letter.Borderless Postcard Postcard.Borderless Custom.WIDTHxHEIGHT MediaType/Media Type: Stationery PhotographicGlossy Com.hpSpecialtyGlossy Com.hpSpecialtyMatte StationeryLightweight cupsPrintQuality/cupsPrintQuality: Draft Normal High ColorModel/Output Mode: RGB Gray Gray16 DeviceGray DeviceRGB AdobeRGB Duplex/Duplex: None DuplexNoTumble DuplexTumble OutputBin/OutputBin: FaceUp

lpoptions -p GARAGE_AIRPRINT

device-uri=ipps://GARAGE_AIRPRINT._ipps._tcp.local/ printer-info=GARAGE_AIRPRINT printer-location=Garage printer-make-and-model='HP ENVY 6000 series' printer-type=83890204


- Cups 2.4.8:

systemctl is-active cups-browsed

inactive

lpoptions -p GARAGE_AIRPRINT -l

PageSize/Media Size: 100x150mm 100x150mm.Borderless 3.5x5 3.5x5.Borderless 4x6 4x6.Borderless 5x7 5x7.Borderless 5x8 5x8.Borderless 8x10 8x10.Borderless A4 A4.Borderless A5 A5.Borderless A6 A6.Borderless B5 B5.Borderless Env10 EnvC6 EnvChou3 EnvChou4 EnvDL Executive ISOB5 Letter Letter.Borderless Postcard Postcard.Borderless Custom.WIDTHxHEIGHT MediaType/Media Type: Stationery PhotographicGlossy Com.hpSpecialtyGlossy Com.hpSpecialtyMatte StationeryLightweight cupsPrintQuality/cupsPrintQuality: Draft Normal High ColorModel/Output Mode: RGB Gray Gray16 DeviceGray DeviceRGB AdobeRGB Duplex/Duplex: None DuplexNoTumble DuplexTumble OutputBin/OutputBin: FaceUp

lpoptions -p GARAGE_AIRPRINT

device-uri=ipps://GARAGE_AIRPRINT._ipps._tcp.local/ printer-info=GARAGE_AIRPRINT printer-location=Garage printer-make-and-model='HP ENVY 6000 series' printer-type=83890204



I'll try to provide the log later. But for screenshots, there's nothing different on the screen. I always have both choices in the combo box (long/short edge), it just always print short edge what ever I choose.
zdohnal commented 4 months ago

@HROMANO ahh, my bad - by screenshots I meant scans of printer outputs (printed papers) when you try to print DuplexNoTumble with 2.4.7 and 2.4.8 (original file would be great as well). Please create two pdf files with two page, where the first page shows the first page of the sheet, and the second the other page if you turn the sheet by long edge.

zdohnal commented 4 months ago

@HROMANO Ad provided data for now - good, I don't see any DuplexTumble (PPD option) or two-sided-short-edge (IPP attribute) in default settings which could override your options from application (they should appear in the log, but I wanted to be sure in case there is a bug which does not show it).

HROMANO commented 4 months ago

Here are the files:

Logs for 2.4.7 (Job 1106):

Logs for 2.4.8 (Job 1107):

I've cut the heads of the logs (previous days, jobs). Not sure how to exactly cut for error_log of 2.4.7 so the first lines are probably not interesting. error_log for 2.4.8 is cut just after the last line of error_log for 2.4.7.

Note: I rebooted between 2.4.7 and 2.4.8 to be sure to run the right version.

HROMANO commented 4 months ago

After bisecting between 2.4.7 and 2.4.8:

0736b61d800cdf866311a60f4b16e4b1fd38230e is the first bad commit
commit 0736b61d800cdf866311a60f4b16e4b1fd38230e (HEAD)
Author: Alexander Pevzner <pzz@apevzner.com>
Date:   Sun Oct 22 22:07:20 2023 +0300

    cups/ppd-cache.c: Add cupsUrfSupported to generated PPD (see #804)

    It fixes driverless printing on Pantum BM5100ADW Series and, probably,
    on many other devices.

    - Without this parameter, /usr/lib/cups/filter/universal generates RGB
    image/urf even for monochrome printer
    - Pantum BM5100ADW Series rejects to print these RGB images with
    the "Print job canceled at printer" status.
    - Probably, this issue affects many other devices

    See #804 for details.

 cups/ppd-cache.c | 14 ++++++++++++++
 1 file changed, 14 insertions(+)

I don't know what is Urf, but not a good idea for my printer…

zdohnal commented 4 months ago

Thank you for bisecting the code and the logs!

URF is a document format for AirPrint and cupsUrfSupported is PPD keyword for its IPP attribute equivalent - urf-supported - it contains printer capabilities which CUPS can take and present them to the user as options which can be applied to the job.

The keyword was added as part of https://github.com/OpenPrinting/cups/issues/804 to work around issue in libcupsfilters, which looks to be fixed now. Probably adding the keyword into PPD file triggered an issue in libcupsfilters, which now I realize it is an issue:

D [23/May/2024:21:43:29 +0200] [Job 1107] Color space requested: Default
D [23/May/2024:21:43:29 +0200] [Job 1107] Final output format: Apple Raster
D [23/May/2024:21:43:29 +0200] [Job 1107] Color mode requested: auto; color depth requested: Standard
D [23/May/2024:21:43:29 +0200] [Job 1107] Determining best color space/depth ...
E [23/May/2024:21:43:29 +0200] [Job 1107] Unable to set color space/depth for Raster output!

The filter hits this error because CUPS now created cupsUrfSupported PPD option which libppd converts back to IPP attribute for ghostscript filter. There is even a difference in ghostscript command:

D [23/May/2024:21:43:29 +0200] [Job 1107] cfFilterGhostscript: Ghostscript command line: gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dUsePDFX3Profile -sstdout=%stderr -sOutputFile=%stdout -sDEVICE=appleraster -sMediaType=Stationery -dDuplex -r300x300 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=841 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=19 -scupsRenderingIntent=auto -scupsPageSizeName=A4 -scupsBackSideOrientation=Normal -dcupsManualCopies -I/usr/share/cups/fonts -sOutputICCProfile=srgb.icc -c \'<</.HWMargins[8.390552 8.390552 8.390564 8.390564] /Margins[0 0]>>setpagedevice\' -f -_

and for 2.4.7

D [23/May/2024:21:32:19 +0200] [Job 1105] cfFilterGhostscript: Ghostscript command line: gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dUsePDFX3Profile -sstdout=%stderr -sOutputFile=%stdout -sDEVICE=appleraster -sMediaType=Stationery -sOutputType=automatic -dDuplex -r300x300 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=19 -dcupsBorderlessScalingFactor=0.0000 -dcupsInteger1=-1 -dcupsInteger2=-1 -dcupsInteger8=4 -scupsRenderingIntent=auto -scupsPageSizeName=A4 -scupsBackSideOrientation=Rotated -dcupsManualCopies -I/usr/share/cups/fonts -sOutputICCProfile=srgb.icc -c -f -_

I suspect -scupsBackSideOrientation different value is the reason of a different output.

Can you get me PPD file which is created at the moment when you print a file? The PPD will be located in /etc/cups/ppd for a minute and then disappears - I would like to check how cupsUrfSupported looks like for you.

Then it would be great if you ran:

$ ipptool --ippserver ipptool.attr ipp://HPA8B13B027068.local:631/ipp/print get-printer-attributes.test

and attached ipptool.attr here as attachment.

Those files will get me idea how urf-supported looks like and whether CUPS transfers it correctly - if the output is okay, then there is at least one issue regarding urf-supported in libcupsfilters...

HROMANO commented 4 months ago

Here are the files for 4.2.8:

zdohnal commented 4 months ago

Ok, we generate the cupsUrfSupported badly:

From IPP response:

ATTR keyword urf-supported "CP1","MT1-2-8-9-10-11","PQ3-4-5","RS300-600","SRGB24","OB9","OFU0","W8-16","DEVW8-16","DEVRGB24-48","ADOBERGB24-48","DM3","IS1","V1.5","FN3"

and what we create:

*cupsUrfSupported: "CP1,MT1-2-8-9-10-11PQ3-4-5RS300-600SRGB24OB9OFU0W8-16DEVW8-16DEVRGB24-48ADOBERGB24-48DM3IS1V1.5FN3"

not enough commas :) ... I'm sorry for that, I'll prepare the fix.

zdohnal commented 4 months ago

Are you able to compile CUPS with the following patch and check if your printer works as expected?

diff --git a/cups/ppd-cache.c b/cups/ppd-cache.c
index 3650f40..d0ed94a 100644
--- a/cups/ppd-cache.c
+++ b/cups/ppd-cache.c
@@ -3511,7 +3511,7 @@ _ppdCreateFromIPP2(
     for (i = 0, count = ippGetCount(attr); i < count; i ++)
     {
       keyword = ippGetString(attr, i, NULL);
-      cupsFilePrintf(fp, "%s%s", keyword, i ? "" : ",");
+      cupsFilePrintf(fp, "%s%s", keyword, i != count - 1 ? "," : "");
     }
     cupsFilePuts(fp, "\"\n");
   }
HROMANO commented 4 months ago

It's good now with the patch. Thanks!

HROMANO commented 3 months ago

I suppose it can be closed now as 2.4.9 is out. Or is there a reason to keep it open?

zdohnal commented 3 months ago

Ouch, thanks! Closing.

compata commented 2 months ago

Although I see this problem closed, I have recently experienced the same issue on Fedora 39 using version 2.4.10.

zdohnal commented 2 months ago

@compata How did/do you install the printer? If you don't install the printer by any way and let CUPS to do its job, then the issue should get fixed automatically. If you have installed the printer via any possible way, then you would need to reinstall the printer.

compata commented 2 months ago

zdohnal wrote:

@compata How did/do you install the printer? If you don't install the printer by any way and let CUPS to do its job, then the issue should get fixed automat ically. If you have installed the printer via any possible way, then you would need to reinstall the printer.

Thanks for the reply. But I'm confused by your question.

I did not "install" the printer. I've had it for several years, working perfectly under Fedora versions from FC34 to FC39. Only recently, after some update, did the problem start. At first, of course, I presumed it was my oversight, failing to specify that I wanted two-sided output. But then I noticed that, having properly requested two-sided, the pages would print strangely. The first side of the first page would print normally, then the paper would retract as though it was about to print the second side, but the page would come out blank. Then the second side of the first page would print on a new sheet of paper, but inverted 180 degrees. Again, this sheet would retract and be ejected with a blank side.

The problem started while I was running Fedora 39. I thought perhaps it would be fixed by an upgrade to Fedora 40 but that did not help. In fact, with FC40, CUPS was unable to find the printer when configured with its DNS name (ipp://printer.mydomain/ipp/print). After converting that to the printer's address (ipp://192.168.xx.xx/ipp/print), I was again able to print. But the two-sided issue did not go away.

I have verified that the CUPS default setting is for two-sided output. I'm running Fedora package cups-2.4.10-1.fc40.x86_64. -- Dave Close, Compata, Irvine CA "You get whatever accomplishment @., +1 714 434 7359 you are willing to declare." @. -- Georgia O'Keeffe

zdohnal commented 2 months ago

So you don't install the printer, but you configure its URI - it looks like you really install the printer permanently via some tool/service.

Please read https://github.com/OpenPrinting/cups/blob/master/REPORTING_ISSUES.md and provide at least the debug logs when you print, output of lpstat -l -e and your printer's generated PPD.

Thank you in advance!

compata commented 2 months ago
# lpstat -l -e
Canon_MG3600_series network none ipps://Canon%20MG3600%20series._ipps._tcp.local/
Cups-PDF permanent ipp://localhost/printers/Cups-PDF cups-pdf:/

# lpstat -t
scheduler is running
system default destination: Canon_MG3600_series
device for Canon_MG3600_series: ipp://192.168.xx.xx/ipp/print
Canon_MG3600_series accepting requests since Mon 22 Jul 2024 12:04:22 AM PDT
Cups-PDF accepting requests since Thu 22 Feb 2024 09:17:38 PM PST
printer Canon_MG3600_series is idle.  enabled since Mon 22 Jul 2024 12:04:22 AM PDT
printer Cups-PDF is idle.  enabled since Thu 22 Feb 2024 09:17:38 PM PST

# lpoptions -l -p Canon_MG3600_series
PageSize/Media Size: 3.5x5 3.5x5.Borderless 4x6 4x6.Borderless 5x7 5x7.Borderless 8x10 8x10.Borderless A4 A4.Borderless A5 B5 Env10 EnvDL Legal *Letter Letter.Borderless Postcard Postcard.Borderless Custom.WIDTHxHEIGHT
InputSlot/Media Source: Auto *Main
MediaType/Media Type: *Stationery Photographic Envelope
cupsPrintQuality/cupsPrintQuality: Draft *Normal High
ColorModel/Output Mode: *RGB Gray
Duplex/Duplex: None *DuplexNoTumble DuplexTumble
OutputBin/OutputBin: *FaceUp

Two-sided printing default set via http://localhost:631. And to reiterate: running Fedora 40 with cups-2.4.10-1.fc40.x86_64. Printer is Canon MG3620. Debug logs and PPD attached. FYI, testpage2.pdf is a simple two-page document I use to test color printing. Printed today with command:

lpr testpage2.pdf -o sides=two-sided-long-edge

ppd.zip log3.txt

zdohnal commented 2 months ago

Note - when examining your data I found a bug in libcups when listing destinations via lpstat - we override user installed permanent queue with temporary - AFAIK the '-l -e' option combination should list available destinations, and IMHO it should prefer user configuration over the network one (but we should report there is a network printer of the same too)

Ad Duplex - Hmm... you have the same duplex type as @HROMANO (DM3), so if it works for him, it should for you, unless there is another variable I'm not aware of or your printer reports the duplex type incorrectly...

Can you try updating your PPD file (copy it, make change in cupsUrfSupported keyword - DM3 -> DM1, reinstall the printer with the updated PPD - lpadmin -p <printer_name> -v <printer_uri> -P <updated_ppd> -E) and try to print?

The change I want to try is changing rotated duplex into normal duplex (some printers rotates the paper when printing duplex) - if it starts working, then we can investigate what capabilities the printer actually reports to CUPS.

compata commented 2 months ago

After this change, printing still took two pages. But the second page was not rotated 180. And there was a peculiar message when entering the command:

# lpadmin -p Canon_MG3600_series -v ipp://canon.compata.com/ipp/print -P Canon_MG3600_series.ppd -E
lpadmin: Printer drivers are deprecated and will stop working in a future version of CUPS.

I thought I was running driverless IPP Everywhere.

BTW, with that URL, CUPS reported, "Unable to get printer status." Changing to my internal IP address instead allowed printing. Name resolution works elsewhere, and formerly worked for CUPS. (The name is resolveable only internally.)

zdohnal commented 2 months ago

@compata ad DNS - there has to be issue with your DNS resolver - I have F40 too and I use internal hostname in printer URI as well, all working

Ad warning - it shows up if the model on CLI is not "everywhere" or not starting with "driverless:" - it does not look into the PPD for the driverless/everywhere strings, so it is false positive...

Can you pass me error_log of the job on the printer with changed PPD? I would like to check if PPD changes were propagated.

compata commented 2 months ago

Sorry for the delay. Attached is a new log file. cups.txt

zdohnal commented 2 months ago

Ok, so the change was applied:

Jul 25 22:11:07 d9020.compata.com cupsd[3485742]: [Job 197] cfFilterGhostscript: Ghostscript command line: gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dUsePDFX3Profile -sstdout=%stderr -sOutputFile=%stdout -      sDEVICE=appleraster -sMediaType=Stationery -dDuplex -r600x600 -dMediaPosition=1 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=19 -scupsRenderingIntent=auto -scupsPageSizeName=Letter -scupsBackSideOrientation=Normal -dcupsManualCopies -I/usr/share/cups/fonts -sOutputICCProfile=srgb.icc -c -f -_

Do you know what CUPS release worked for you? 2.4.8/2.4.7? You can find all CUPS builds in koji https://koji.fedoraproject.org/koji/packageinfo?packageID=54 , F40 builds go back even till 2.4.6.

I suspect generating cupsUrfSupported might be the one causing the issue, the exact version could help us narrowing the range of commits where the change happened and could confirm the cupsUrfSupported change is the real culprit - the original report was too due cupsUrfSupported.

compata commented 2 months ago

Searching back through my DNF logs, I see the following installation history: 2024-07-20 cups-2.4.10-1.fc40 2024-07-13 cups-2.4.8-3.fc39 -> 2.4.10-1.fc39 2024-06-01 cups-2.4.7-13.fc39 -> 2.4.8-3.fc39 2024-04-18 cups-2.4.7-11.fc39 -> 2.4.7-13.fc39 2024-02-25 cups-2.4.7-5.fc39 -> 2.4.7-11.fc39 I can't say for sure when the problem started but at least three months ago. So probably 2.4.7-11 or 2.4.7-13 worked.

zdohnal commented 2 months ago

F40 packages are the same - you can download the same NVR for F40 it should give the same experience (I'm CUPS maintainer in Fedora, if you don't guess it already and I kind of recall your nick too :D ) - if not, the problem lies somewhere else.

Please try cups-2.4.7-13.fc40 and check if there is a change.

compata commented 2 months ago
# rpm -q --requires cups-2.4.7-13.fc40
...
cups-filesystem = 1:2.4.7-13.fc40

That package, cups-filesystem, is not in the kodi list. I wonder why it is required anyway.

zdohnal commented 2 months ago

It is in the koji list under noarch - if the package contains only files which do not depend on architecture they were built on (here it is directories, but most python packages are noarch as well, since they are scripts independent on arch - only if their bytecompiled files are shipped, they become arch dependent, f.e. system-config-printer).

compata commented 2 months ago

I downgraded to cups-2.4.7-13.fc40.x86_64.rpm , cups-ipptool-2.4.7-13.fc40.x86_64.rpm, cups-client-2.4.7-13.fc40.x86_64.rpm, cups-libs-2.4.7-13.fc40.x86_64.rpm, cups-devel-2.4.7-13.fc40.x86_64.rpm, cups-lpd-2.4.7-13.fc40.x86_64.rpm, and cups-filesystem-2.4.7-13.fc40.noarch.rpm, and restarted cups. My command, "lpr.cups -o sides=two-sided-long-edge ~/testpage2.pdf", used two sheets of paper, just as before.

Why did commands like "lpr" and "lpq" get changed to "lpr.cups" and lpq.cups"?

zdohnal commented 2 months ago

@compata have you reinstalled the printer? Since you decided to install the printer permanently, you have to regenerate the PPD which got generated for the printer.

lpr is still available - the only change I did was to define /usr/bin/lpr and friends as ghost files, because they are artificially created by alternatives, but they weren't removed with cups-client during uninstall.

compata commented 2 months ago

Sorry, I should have done that. After running "modify printer" through http://localhost:631, 2-sided printing is working as it should. I made no actual changes during the modify but the PPD file had these few changes:

# diff -s new original
19c19
< *APSupplies: "http://0A17D0000000.local./index.html?page=PAGE_AAP"
---
> *APSupplies: "http://192.168.44.150/index.html?page=PAGE_AAP"
22a23
> *cupsUrfSupported: "V1.4,CP1,PQ4-5,RS600,SRGB24,W8,OB9,OFU0,DM1,IS1"
zdohnal commented 1 month ago

Ok, that confirms my suspicion, that the behavior is related to cupsUrfSupported workaround introduced to work around bug in libppd (which is fixed in Fedora by backported patch, but I left the CUPS upstream source as it is)...

But it looks like a different issue, since the original issue works for the original reporter... I'll create a new issue for it.