Bug 691755 - PDF rendering slow with high resolution for printing, especially documents with images and transparency
Summary: PDF rendering slow with high resolution for printing, especially documents wi...
Status: RESOLVED FIXED
Alias: None
Product: Ghostscript
Classification: Unclassified
Component: PDF Interpreter (show other bugs)
Version: master
Hardware: PC Linux
: P4 major
Assignee: Robin Watts
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-11-07 14:25 UTC by Till Kamppeter
Modified: 2014-02-17 04:44 UTC (History)
5 users (show)

See Also:
Customer:
Word Size: ---


Attachments
stars.pdf (104.57 KB, application/pdf)
2010-11-07 14:25 UTC, Till Kamppeter
Details
output.pdf (1.06 MB, application/pdf)
2010-11-07 14:27 UTC, Till Kamppeter
Details
stars.pdf raw callgrind profile (763.07 KB, text/plain)
2010-11-10 11:43 UTC, Chris Liddell (chrisl)
Details
stars.pdf annotated callgrind profile (5.87 KB, text/plain)
2010-11-10 11:44 UTC, Chris Liddell (chrisl)
Details
stars.pdf -dNOTRANSPARENCY raw callgrind profile (719.80 KB, text/plain)
2010-11-10 14:19 UTC, Chris Liddell (chrisl)
Details
stars.pdf -dNOTRANSPARENCY annotated callgrind profile (3.61 KB, text/plain)
2010-11-10 14:20 UTC, Chris Liddell (chrisl)
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Till Kamppeter 2010-11-07 14:25:42 UTC
Created attachment 6874 [details]
stars.pdf

On Ubuntu Linux, where printing is done with a PDF-based workflow, Ghostscript is usually run with PDF as input format when print jobs for non-PostScript printers need to be rendered. There often come up complaints that printing is too slow or that Ghostscript even runs out of system resources. The input files usually contain images or transparency. On simple text files there are no performance complaints.

Here are some example bug reports:

https://bugs.launchpad.net/ubuntu/+source/ghostscript/+bug/668800
https://bugs.launchpad.net/ubuntu/+source/ghostscript/+bug/568363

The sample files, already passed through the application's printing function are attached.

The following command line reproduces the slow rendering problem:

time /usr/bin/gs -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -sDEVICE=cups -sstdout=%stderr -sOutputFile=%stdout -I/usr/share/cups/fonts -r720x720 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=841 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=1 -dcupsCompression=1 -scupsPageSizeName=A4 -c -f stars.pdf > out.raster

The problem appears with any output device if the resolution is high enough and the output is full color:

time /usr/bin/gs -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -sDEVICE=png16m -sstdout=%stderr -sOutputFile=%stdout -r720x720 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=841 stars.pdf > out.png

So the problem is in the PDF interpreter and not in the output devices.

In addition, only output.pdf gets correctly rendered. In stars.pdf only the first star appears in the output file.
Comment 1 Till Kamppeter 2010-11-07 14:27:40 UTC
Created attachment 6875 [details]
output.pdf
Comment 2 Till Kamppeter 2010-11-07 15:45:35 UTC
The reporter of

https://bugs.launchpad.net/ubuntu/+source/ghostscript/+bug/668800

tells in addition:

I've noticed this mainly affects documents with objects that are blurred and transparent. Eg. create an object in inkscape and set opacity to 80 and blur to 40; and the printer becomes lethargic. A shape with opacity set to 100 and blur set to 0 prints in the blink of an eye.

This means that especially transparency effects slow down PDF rendering.
Comment 3 Ray Johnston 2010-11-09 19:00:52 UTC
This will probably be helped quite a bit by implementing the changes
suggested in bug 691607. Chris said that this has some large bbox transparency
groups that might not really need transparency everywhere.
Comment 4 Chris Liddell (chrisl) 2010-11-10 11:43:50 UTC
Created attachment 6883 [details]
stars.pdf raw callgrind profile
Comment 5 Chris Liddell (chrisl) 2010-11-10 11:44:40 UTC
Created attachment 6884 [details]
stars.pdf annotated callgrind profile
Comment 6 Chris Liddell (chrisl) 2010-11-10 11:45:15 UTC
I just confirmed the problems are the same for both the examples Till uploaded (and the one referenced on the Ubuntu bug tracker), and they are the same - but a bit more subtle than I appreciated yesterday.


The problem of the group bounding box being the dimensions of the page is compounded massively because we have constructs of the form:
Page Trans Group (BBox == page dimensions)
 -> Type 1 Pattern (BBox == page dimensions)
  -> Trans Group (BBox == page dimensions)


As a consequence the pattern device does not use a clist (despite the pattern bitmap buffer being *much* bigger than MaxPatternBitmap), but is forced to render to a bitmap buffer. Then the PaintProc contains at least one (possibly more nested) transparency groups, each of which also allocates a contone buffer (again covering the full page size).

This means we end up with one or more (I believe) very large low level images being written to the clist.

The large areas of alleged transparency requiring compositing account for the heavy memory demands, and some performance, plus the very large low level clist images accounts for the remaining performance.

I've attached some profile information for stars.pdf from callgrind both the annotated and raw data (view the raw data with Kcachegrind maybe WinCachegrind, too?). The two top time consumers are _wordcopy_fwd_dest_aligned (called from memmove, in turn called from clist_playback_band), and pdf14_compose_group.

I believe the correct solution would be to assess why the patten clist does not work when the pattern uses transparency, and revise/enhance it to do so - if that is even possible. Or possibly complete the "high level pattern" support in the page clist.

A quick and dirty solution (I'm not sure how quick it would be to implement) might to disable pattern caching for patterns which use transparency (or maybe just at high resolutions), and repeatedly invoke the PaintProc (this might also provide the opportunity to implemente MaxPatternItem and MaxPatternCache settings).


Finally, I note that even with -dNOTRANSPARENCY stars.pdf takes over 3 minutes on my machine (Intel Core2 Quad CPU @ 3.00GHz) at 720dpi, which is not exactly quick for what is, without the transparency, a fairly simple job. I'll attach a profile for this, too, when the run completes.
Comment 7 Chris Liddell (chrisl) 2010-11-10 14:19:03 UTC
Created attachment 6885 [details]
stars.pdf -dNOTRANSPARENCY raw callgrind profile
Comment 8 Chris Liddell (chrisl) 2010-11-10 14:20:56 UTC
Created attachment 6886 [details]
stars.pdf -dNOTRANSPARENCY annotated callgrind profile

Without transparency, most of the time is spent in image interpolation.

Indeed, with -dNOTRANSPARENCY *and* -dNOINTERPOLATE it only takes 19 seconds to render (rather than over 3 minutes) at 720dpi.
Comment 9 Ray Johnston 2010-11-10 16:57:27 UTC
Note that Michael has implemented pattern-clist with transparency for customer
532, but he needs to do more work on it (when he has time) to finish it up and
commit it -- I had to do a fair amount of work on it after he gave it to me
just before his vacation. It works in cust 532 code, but I don't have time to
merge my changes back to SVN just yet, either. It will probably get wrapped
up in a week or so.
Comment 10 Michael Vrhel 2010-11-11 17:14:51 UTC
Yes.  The pattern with trans clist stuff should fix this.  I will try to get the information of what I need to fix from Ray today.
Comment 11 Till Kamppeter 2010-11-29 22:53:07 UTC
The file attached to comment #3 of this Ubuntu bug

https://bugs.launchpad.net/bugs/355801

is also a good example to reproduce the slowness of Ghostscript on certain PDF files.
Comment 12 Till Kamppeter 2010-11-30 17:16:44 UTC
Sorry, I meant

https://bugs.launchpad.net/bugs/680628

in the previous comment.
Comment 13 pipitas 2011-02-09 21:41:53 UTC
A simple

  gs starts.pdf

yields this output for me:

kp@kpuntu:~/Downloads$ /usr/local/bin/gs stars.pdf 
 GPL Ghostscript RELEASE CANDIDATE 9.01 (2011-02-07)
 Copyright (C) 2010 Artifex Software, Inc.  All rights reserved.
 This software comes with NO WARRANTY: see the file PUBLIC for details.
 Processing pages 1 through 1.
 Page 1
 Error: /rangecheck in --run--
 Operand stack:
    --dict:7/16(L)--   x6   --nostringval--   0.0   0.0   0.0   --nostringval--   true   707   0   1
 Execution stack:
    %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1894   1   3   %oparray_pop   1893   1   3   %oparray_pop   1877   1   3   %oparray_pop   --nostringval--   --nostringval--   2   1   1   --nostringval--   %for_pos_int_continue   --nostringval--   --nostringval--   false   1   %stopped_push   --nostringval--   --nostringval--
 Dictionary stack:
    --dict:1150/1684(ro)(G)--   --dict:1/20(G)--   --dict:82/200(L)--   --dict:82/200(L)--   --dict:108/127(ro)(G)--   --dict:295/300(ro)(G)--   --dict:23/30(L)--   --dict:6/8(L)--   --dict:21/40(L)--   --dict:1/1(ro)(G)--   --dict:5/5(L)--   --dict:5/5(L)--   --dict:18/25(L)--
 Current allocation mode is local
 Last OS error: 11
 GPL Ghostscript RELEASE CANDIDATE 9.01: Unrecoverable error, exit code 1


The executable gs I compiled just now from SVN r12134 (using default configure settings). However, the (almost) same output is with GS8.71:


kp@kpuntu:~/Downloads$ /usr/bin/gs stars.pdf 
 GPL Ghostscript 8.71 (2010-02-10)
 Copyright (C) 2010 Artifex Software, Inc.  All rights reserved.
 This software comes with NO WARRANTY: see the file PUBLIC for details.
 Processing pages 1 through 1.
 Page 1
 Error: /rangecheck in --run--
 Operand stack:
    --dict:7/16(L)--   x6   0.0   0.0   0.0   --nostringval--   true   707   0
 Execution stack:
    %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1878   1   3   %oparray_pop   1877   1   3   %oparray_pop   1861   1   3   %oparray_pop   --nostringval--   --nostringval--   2   1   1   --nostringval--   %for_pos_int_continue   --nostringval--   --nostringval--   false   1   %stopped_push   --nostringval--   --nostringval--
 Dictionary stack:
    --dict:1153/1684(ro)(G)--   --dict:1/20(G)--   --dict:75/200(L)--   --dict:75/200(L)--   --dict:108/127(ro)(G)--   --dict:287/300(ro)(G)--   --dict:22/25(L)--   --dict:6/8(L)--   --dict:21/40(L)--   --dict:1/1(ro)(G)--   --dict:5/5(L)--   --dict:5/5(L)--   --dict:6/15(L)--
 Current allocation mode is local
 Last OS error: 11
 GPL Ghostscript 8.71: Unrecoverable error, exit code 1
Comment 14 Chris Liddell (chrisl) 2011-02-09 21:50:54 UTC
(In reply to comment #13)
> A simple
> 
>   gs starts.pdf
> 
> yields this output for me:
<SNIP>

If this is using x11alpha, the problems with that device and transparency are well known and being tracked elsewhere, and not relevant to this bug.

You could try the x11 device instead.
Comment 15 Till Kamppeter 2011-02-09 22:01:56 UTC
Because of this problem I have switched the default output device of Ghostscript to "x11" in 9.01.
Comment 16 Ray Johnston 2011-06-01 18:11:34 UTC
Should this bug be closed now that Robin has finished the pattern-trans-clist
implementation ?
Comment 17 Robin Watts 2011-06-03 16:54:49 UTC
This has been fixed, with the patt_trans_clist work now being merged to the master. (Commit http://git.ghostscript.com/?p=ghostpdl.git;a=commit;h=44e59fd123729ba05f8728f01d13406d3e283855).

Please let us know of any remaining problems. Many thanks.
Comment 18 Till Kamppeter 2011-07-15 19:45:57 UTC
I do not know whether the problem is still the same, but I still have the problem of too slow rendering of the attached files also with Ghostscript 9.04 (GIT rev 2472633cba141873 from July 15, 2011). Now stars.pdf is correctly rendered, showing all 6 stars, but rendering is still extremely slow when using the command lines of the initial comment.
Comment 19 Robin Watts 2011-07-21 15:24:47 UTC
Believed fixed in git commit c9a8f8b.

commit c9a8f8b3b0327bb62fc79cfe93d6bd79f997a2b6
Author: Robin Watts <Robin.Watts@artifex.com>
Date:   Tue Jul 19 20:02:50 2011 +0100

    pdf14 'dirty' rect optimisations.

    Rename 'bbox' to 'dirty' - makes the purpose of the field much clearer.

    Export dirty rectangle pointer in gx_pattern_trans_t structure.

    Remove automatic expansion of 'dirty' rects to full rect boundary.

    Ensure tiling code sets dirty rectangle as expected.

    Remove debugging printfs.

    Testing shows 491 differences. 16 or so real changes (all neutral or
    progressions), but most of them in the cups device. Manual testing
    shows no changes at all - no idea what's going on there.


After this commit stars.pdf renders in 10 minutes at 720dpi on my machine, or 2 and a bit minutes if -dNOINTERPOLATE is used.
Comment 20 Till Kamppeter 2011-07-21 19:32:06 UTC
I tested and found out that the Ghostscript output for both CUPS Raster and PNG is absolutely identical with and without -dNOINTERPOLATE. So I consider using it by default in print filters.