Bug 691755

Created attachment 6875 [details]
output.pdf

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.

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.

Created attachment 6883 [details]
stars.pdf raw callgrind profile

Created attachment 6884 [details]
stars.pdf annotated callgrind profile

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.

Created attachment 6885 [details]
stars.pdf -dNOTRANSPARENCY raw callgrind profile

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.

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.

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.

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.

Sorry, I meant

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

in the previous comment.

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

(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.

Because of this problem I have switched the default output device of Ghostscript to "x11" in 9.01.

Should this bug be closed now that Robin has finished the pattern-trans-clist
implementation ?

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.

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.

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.

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.