Bug 404549 - Printing N copies results in N^2 copies printed instead
Summary: Printing N copies results in N^2 copies printed instead
Status: RESOLVED WORKSFORME
Alias: None
Product: okular
Classification: Applications
Component: printing (show other bugs)
Version: 1.6.2
Platform: Arch Linux Linux
: NOR normal
Target Milestone: ---
Assignee: Okular developers
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-02-19 11:23 UTC by freeze_ball
Modified: 2020-06-30 20:18 UTC (History)
3 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments
Cups log set to debug. (284.33 KB, text/x-log)
2019-02-22 09:08 UTC, freeze_ball
Details
/var/spool/cups/d01096-001 (30.04 KB, application/postscript)
2019-02-22 09:15 UTC, freeze_ball
Details
/etc/cups/ppd/Kyocera_TASKalfa_1801.ppd (45.14 KB, application/vnd.cups-ppd)
2019-02-22 09:18 UTC, freeze_ball
Details
/tmp/okular_vTQSft.ps (30.04 KB, application/postscript)
2019-02-22 09:28 UTC, freeze_ball
Details

Note You need to log in before you can comment on or make changes to this bug.
Description freeze_ball 2019-02-19 11:23:35 UTC
SUMMARY
Instead of printing N copies of PDF document from Okular it prints N*N copies of it.

STEPS TO REPRODUCE
1. Open PDF document in Okular;
2. Open printing GUI;
3. Set number of copies to print at more than 1;

OBSERVED RESULT
Printer outputs more pages than you expect. For example, if the document is 4 sheets and I set it to print 3 copies of it, printer output total of 36 sheets, each sheet is copied 9 times. If it is set to "collate", it prints in order like this: AAABBBCCCDDD then repeats that 2 more times (AAABBBCCCDDDAAABBBCCCDDDAAABBBCCCDDD in total of 36 sheets). 1 sheet document in 2 copies outputs 4 sheets and 1 sheet document in 5 copies prints 25.

EXPECTED RESULT
Printer does not waste paper and toner on unnecessary unexpected copies.

SOFTWARE/OS VERSIONS
Linux/KDE Plasma: Linux 4.20.8-arch1-1-ARCH; 
KDE Plasma Version: 5.15.0
KDE Frameworks Version: 5.55.0
Qt Version: 5.12.1

ADDITIONAL INFORMATION
To get expected behavior until the issue is resolved I start printing job from Okular N times as 1 copy.

Tried two different PC's with different installations of Archlinux, both are fully updated. Using cups, tried with two different printers: Kyocera TASKalfa 1801 and Brother MFC-L2700DWR with manufacturer's drivers; all printing "last minute" settings are default except for number of copies in Okular's GUI. No other program copies this behavior.

Cups logs at default level do not output anything exceptional.

I HAVE checked all "Possible duplicates" bugs suggested by the site engine and haven't found a solution.
Comment 1 Nate Graham 2019-02-19 16:33:58 UTC
Cannot reproduce with git master, FWIW.
Comment 2 Michael Weghorn 2019-02-21 07:29:07 UTC
This sounds like it might be related to the CUPS filter chain, rather than Okular.

The following information might help to further narrow this down:

1) Does this happen for all files or just specific ones?

2) Can you attach the CUPS log for one such print job (with LogLevel set to debug)?

3) the file as generated by Okular: Can you (using a non-confidential file)
* temporarily disable the printer using 'sudo cupsdisable <PRINTER_NAME>'
* start printing from Okular
* attach the print file called 'd<JOB_ID>_001' from directory '/var/spool/cups' (which should be a PostScript file)
You can then enable the printer again using 'sudo cupsenable <PRINTER_NAME>?

4) Can you attach the PPD files of the printer(s), which should be located at /etc/cups/ppd/<PRINTER_NAME>?

5) What is the device URI of the printer (which is shown e.g. when running 'lpstat -v'?

6) Can you attach the file as generated by the CUPS filters? In order to get this, you can set up a dummy printer that prints to a file as follows:
* set 'FileDevice Yes' in /etc/cup/cups-files.conf
* restart CUPS
* set up a dummy printer that prints to a file, using the real printer's PPD file:
  'sudo lpadmin -p tofile -v file:/tmp/tofile -P /etc/cups/ppd/<PRINTER_NAME> -E'
* print the PDF file from Okular to the "tofile" printer
* attach the file that is generated at /tmp/tofile
Comment 3 freeze_ball 2019-02-22 09:08:12 UTC
Created attachment 118279 [details]
Cups log set to debug.
Comment 4 freeze_ball 2019-02-22 09:15:46 UTC
Created attachment 118280 [details]
/var/spool/cups/d01096-001
Comment 5 freeze_ball 2019-02-22 09:18:33 UTC
Created attachment 118281 [details]
/etc/cups/ppd/Kyocera_TASKalfa_1801.ppd
Comment 6 freeze_ball 2019-02-22 09:28:34 UTC
Created attachment 118282 [details]
/tmp/okular_vTQSft.ps
Comment 7 freeze_ball 2019-02-22 09:30:38 UTC
(In reply to Michael Weghorn from comment #2)

1. All PDF-files opened with Okular: ones got from e-mail via Thunderbird and Firefox, and ones generated by LibreOffice.

2. For this test I ran a pdf file with 3 empty pages as 3 copies (it has output 27 sheets of paper) after this command:
# tail -n 100 -f /var/log/cups/error_log >> ~/cups.log
cups.log contents: https://bugs.kde.org/attachment.cgi?id=118279

3. For this job I ran a pdf file with 3 pages with only their numbers as 3 copies (27 sheets of paper)
# cupsdisable Kyocera_TASKalfa_1801
PostScript file for this job: https://bugs.kde.org/attachment.cgi?id=118280

4. PPD file is attached here: https://bugs.kde.org/attachment.cgi?id=118281

5. Kyocera_TASKalfa_1801: usb://Kyocera/TASKalfa%201801?serial=LBG7310105
When I connect it through the LAN, it looks like this 
Kyocera_TASKalfa_1801: lpd://192.168.0.102/Kyocera1801

6. After
# mcedit /etc/cups/cups-files.conf
setting 'FileDevice Yes'
# systemctl restart org.cups.cupsd
# lpadmin -p tofile -v file:/tmp/tofile -P /etc/cups/ppd/Kyocera_TASKalfa_1801.ppd
and printing pdf file from #3 to "tofile" printer as 3 copies I got this file in /tmp: https://bugs.kde.org/attachment.cgi?id=118282
Comment 8 Albert Astals Cid 2019-02-26 22:50:34 UTC
Data asked was provided, back to reported
Comment 9 Michael Weghorn 2019-02-27 12:52:38 UTC
Thanks for all the information. I don't see anything obvious at first sight.

However, the file you attached for 6 is another one, and the comment for the attachment also says '/tmp/okular_vTQSft.ps'. It's the file generated by Okular (identical to the one from step 3), not the one generated by the CUPS filters. The other file should have been saved as "/tmp/tofile", but it may be that CUPS wasn't allowed to write '/tmp' due to some system restrictions (e.g. AppArmor policies,...).
You might try using another path, e.g. '$HOME/tofile', i.e. use the '-v file:$HOME/tofile' option for the lpadmin command and see whether this works.

Anyway the CUPS log shows that this is the CUPS filter chain for the print job:

> D [22/Feb/2019:11:51:36 +0300] [Job 1095] 4 filters for job:
> D [22/Feb/2019:11:51:36 +0300] [Job 1095] gstopdf (application/postscript to application/pdf, cost 0)
> D [22/Feb/2019:11:51:36 +0300] [Job 1095] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
> D [22/Feb/2019:11:51:36 +0300] [Job 1095] gstoraster (application/vnd.cups-pdf to application/vnd.cups-raster, cost 99)
> D [22/Feb/2019:11:51:36 +0300] [Job 1095] /usr/lib/cups/filter/rastertokpsl_A3 (application/vnd.cups-raster to printer/Kyocera_TASKalfa_1801, cost 0)

Some more questions:

A) Do you know where the '/usr/lib/cups/filter/rastertokpsl_A3' filter comes from? Is it some (proprietary) binary provided by the vendor (Kyocera)?

B) Is the result the same when you manually print the file from step 3 using the following command (using the options from the CUPS log)?

lp -d Kyocera_TASKalfa_1801 -n 3  -o "Collate finishings=3 fit-to-page job-billing media=A4 number-up=1 number-up-layout=lrtb outputorder=normal page-bottom=10 page-left=12 page-right=12 page-top=10 portrait sides=one-sided Duplex=None PageSize=A4" d01096-001

C) And does anything change if you leave out all the specific options and just use this command:

lp -d Kyocera_TASKalfa_1801 -n 3  d01096-001

To check whether one of the filters does something odd, you can check their "intermediate" results. Using the file from step 3, you can run the first filter using

PPD=/etc/cups/ppd/Kyocera_TASKalfa_1801.ppd /usr/lib/cups/filter/gstopdf 1 $USER title 3 "Collate finishings=3 fit-to-page job-billing media=A4 number-up=1 number-up-layout=lrtb outputorder=normal page-bottom=10 page-left=12 page-right=12 page-top=10 portrait sides=one-sided Duplex=None PageSize=A4" d01096-001 > result_from_gstopdf

and then check the file "result_from_gstopdf" whether it has 3 pages or more

Then using that file, you can run the next filter:

PPD=/etc/cups/ppd/Kyocera_TASKalfa_1801.ppd /usr/lib/cups/filter/pdftopdf 1 $USER title 3 "Collate finishings=3 fit-to-page job-billing media=A4 number-up=1 number-up-layout=lrtb outputorder=normal page-bottom=10 page-left=12 page-right=12 page-top=10 portrait sides=one-sided Duplex=None PageSize=A4" result_from_gstopdf > result_from_pdftopdf

and check its result again, etc. (though I'm not sure what format the last filter generates and whether you can simply view it).
Comment 10 freeze_ball 2019-03-07 10:48:21 UTC
Yes, it is clear now for me that the issue is proprietary filters from the manufacturer. I am marking this thread as "RESOLVED" for now, and to work around the issue I will just print 1 copy multiple times. Thank you for your time, gentlemen.