Bug 700380 - Printing job in 16.04 is slower than in 14.04
Summary: Printing job in 16.04 is slower than in 14.04
Status: RESOLVED INVALID
Alias: None
Product: Ghostscript
Classification: Unclassified
Component: Printer Driver (show other bugs)
Version: 9.26
Hardware: PC Linux
: P4 normal
Assignee: Default assignee
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-12-17 09:48 UTC by YangGuangJing
Modified: 2018-12-19 10:31 UTC (History)
1 user (show)

See Also:
Customer:
Word Size: ---


Attachments
Add Log file: (255.60 KB, application/x-zip-compressed)
2018-12-17 09:49 UTC, YangGuangJing
Details
Sample file (402.11 KB, application/x-zip-compressed)
2018-12-18 06:55 UTC, YangGuangJing
Details

Note You need to log in before you can comment on or make changes to this bug.
Description YangGuangJing 2018-12-17 09:48:38 UTC
OS Version:	 16.04
Ghostscript Version:	9.18


We find a problem about ghostscript:
Print file on Ubuntu 14.04, Ghostscript 9.10 is fast.

But, after I update to Ubuntu 16.04, Ghostscript 9.18, I print the same file with the same driver is slow.

I figure out that all the print jobs is much slower 60%(Or more slower) on Ubuntu 16.04 than Unbuntu 14.04.

I view the "CUPS Error Log"(Log.zig), it shows that Ghostscript may be the key process that makes the print job slowly.

By counting the time from " Starting process "renderer"" to " Closing renderer", we figure out that ghostscript of 16.04 spend more time than 14.04 on "renderer" process.
So we assuming that:"renderer" is the key process that makes the print job slowly.

So it seems that the newer Ghostscript version used by 16.04 is processed much slower by your printer than the PostScript of 14.04's Ghostscript version.

By the way, more and more our printer driver users are affect by this problem.
So, we are eagerly want to know that you can dealing with this problem ASAP.
And we hope that you can share the investigation with us.


Attach file introduction:
----------------------------------------------------------
Test log:
Ubuntu14.04,Job621-Job630:    \log\Ubuntu_14.04_error_log_Job621_630
Ubuntu16.04,Job621-Job630:    \log\Ubuntu_16.04_error_log_Job621_630
----------------------------------------------------------

Test Driver:
Driver carry by Ubuntu14.04 and Ubuntu16.04 itself :”Ricoh MP C5503 PXL”

Print Output:
file:/test.prn

Print file:
OS Testpage.

We test many commercial’s drivers (below), it shows that other drivers(use ghostsrcipt) have the same slower phenomenon:
HP Color LaserJet 2500 Foomatic/pxlcolor
HP Color LaserJet 3600 Foomatic/pxljr
Brother HL-7050  Foomatic/pxlmono
Brother MFC9840CDW  Foomatic/pxlcolor
Comment 1 YangGuangJing 2018-12-17 09:49:50 UTC
Created attachment 16576 [details]
Add Log file:
Comment 2 Chris Liddell (chrisl) 2018-12-17 09:55:47 UTC
First, try an up to date Ghostscript: the latest release is 9.26.

Secondly, if that doesn't help, we cannot investigate without an example file to reproduce the problem. A cups log is not really any use to us.
Comment 3 Chris Liddell (chrisl) 2018-12-17 09:56:54 UTC
I should have also said: an example file which is the input to Ghostscript (so Postscript or PDF).
Comment 4 YangGuangJing 2018-12-18 06:55:06 UTC
Dear Chris,
  >First, try an up to date Ghostscript: the latest release is 9.26.
  We had tried to use ghostscript 9.26 to print the same jobs, the investigation  result shows that the newest version 9.26 is still have the same slower phenomenon.

  >an example file which is the input to Ghostscript (so Postscript or PDF).
  We use a PDF file(sample.pdf) to do the investigation, which we attach in sample.zip.

Best Regards,
Comment 5 YangGuangJing 2018-12-18 06:55:35 UTC
Created attachment 16594 [details]
Sample file
Comment 6 Chris Liddell (chrisl) 2018-12-18 09:56:42 UTC
Well, running locally using the command line options:
time gs -q -dNOPAUSE -dBATCH -dSAFER -sDEVICE=ps2write -sOUTPUTFILE=/dev/null -dLanguageLevel=3 -r600 -dCompressFonts=false -dNoT3CCITT -dNOINTERPOLATE -c "save pop" -f sample.pdf

(writing to /dev/null to avoid i/o variations).

I get 9.16 giving:
real	0m0.835s
user	0m0.819s
sys	0m0.016s


and 9.26 giving:
real	0m0.453s
user	0m0.441s
sys	0m0.012s

So, as far as I can see, 9.26 is considerably *faster* than 9.16.
Comment 7 YangGuangJing 2018-12-18 10:48:42 UTC
Dear Chris,

First, we found that the gs version 9.10(not 9.16) command execute faster than version 9.18 / 9.26.

Second, the "sDEVICE" we point out is "pxlcolor".
The following gs command in our log file slow down with version 9.18 / 9.26 than version 9.10.

gs -q -dBATCH -dPARANOIDSAFER -dNOPAUSE -dNOINTERPOLATE  -sDEVICE=pxlcolor -r600x600 -sPAPERSIZE=a4 -sOutputFile=- -
Comment 8 Chris Liddell (chrisl) 2018-12-18 11:22:54 UTC
Okay, will using:
time ./gs -q -dBATCH -dPARANOIDSAFER -dNOPAUSE -dNOINTERPOLATE  -sDEVICE=pxlcolor -r600x600 -sPAPERSIZE=a4 -sOutputFile=/dev/null sample.pdf


I get, from 9.10:

real	0m0.271s
user	0m0.263s
sys	0m0.008s


And from 9.26, I get:

real	0m0.316s
user	0m0.308s
sys	0m0.008s


So there is difference in the favour of 9.10, but it's pretty hard to see how that translates into an observable slow down within the cups infrastructure.

Perhaps if you supply a Ghostscript command line, and the results you see from running that command with "time", it might help narrow down what's going on.
Comment 9 YangGuangJing 2018-12-18 11:37:03 UTC
Dear Chris,

Thanks a lot for your suggestion. We'll try the gs command with "time".
And if there is new phenomenon, contact you later.
Comment 10 YangGuangJing 2018-12-19 09:58:16 UTC
Dear Chris,

We tried the gs command as below, and found the gs version 9.26(on Ubuntu 16.04) is about 30%(0.1s) slower than version 9.10(on Ubuntu 14.04).

time ./gs -q -dBATCH -dPARANOIDSAFER -dNOPAUSE -dNOINTERPOLATE  -sDEVICE=pxlcolor -r600x600 -sPAPERSIZE=a4 -sOutputFile=/dev/null sample.pdf


gs version 9.10(on Ubuntu 14.04):
real	0m0.743s
user	0m0.321s
sys	0m0.036s


gs version 9.26(on Ubuntu 16.04):
real	0m0.782s
user	0m0.419s
sys	0m0.021s

*The time is changing when try again, but still the "user time" is about 30% (0.1s)slower with gs version 9.26 than with 9.10.

*Our Ubuntu 14.04 64bit and Ubuntu 16.04 64bit machines have the same hardware configuration.


I saw your "user time" with gs version 9.26 is only about 17%(0.04s) slower than 9.10. 
Would you mind to tell me if your two machines which run gs version 9.26 and 9.10 have the same hardware configuration?

Although 0.1 second is tiny in one print job, but when hundreds of thousands jobs be print in the meantime, the slowing down became obvious.
Would you mind to do some analysis to find out the reason of the slowing down phenomenon?
Comment 11 Chris Liddell (chrisl) 2018-12-19 10:31:51 UTC
Both my tests were run on the same machine. I also ran the tests 5 times each, to ensure I wasn't seeing an outlier result from a single execution - in this case the times were so close, it wasn't worth averaging them.


Sorry, but frankly, no, I won't be doing analysis to find a 0.04 (or less) second slow down. If you take a look at our git history between 9.10 and 9.18 you'll find over 1000 commits, many of which were to cope with broken or out spec PDF files, and most of which required extra work to deal with such cases. Any one, or combination of those could be the culprit.

If you can identify a small (<5 pages) job that exhibits a more pronounced slow down (>2 seconds difference, ideally), then feel free to attach it here, and reopen this, and then I (or one of us) will look at it.