Bug 64892

I'm not sure if we can do much here: once again we have a PDF which was produced from a postscript file, and this results in 48096 (!!!) calls of tilingPatternFill. So not the tilingPatternFill itself but the amount of calls of it makes rendering such slow.
Xpdf (3.0.3) uses another implementation of tilingPatternFill in splash, I'd a look at it during merging and decided to let our implementation in because of the better quality.
But I had also a deeper look into the PDF: it uses just 5 or 6 pattern colorspaces (which results into calls of tilingPatternFill), perhaps it could be a little bit faster to cache intermediate results if possible. But this would be a greater task, and I'm not able to work on it in the next three months because of some private issues.
And I encountered that we made a mistake during merging a tilingPatternFill enhancement and Adrian's work on bilinear interpolation. This causes that scaleImageYuXuBilinear is called for every tilingPatternFill, which is not necessary in my opinion.

Created attachment 79711 [details] [review]
avoid call of bilinear interpolation in case of tilingPatternFill

As I said: in my opinion the bilinear interpolation is not necessary in case of tilingPatternFill. This patch avoids it and increases the speed of rendering page 3 on my laptop a little bit:

before:
date; utils/pdftoppm -cropbox -png -r 72 -f 3 -l 3 sample2.pdf sample2; date
Do 23. Mai 13:56:51 CEST 2013
 Do 23. Mai 14:24:27 CEST 2013

after:
date; utils/pdftoppm -cropbox -png -r 72 -f 3 -l 3 sample2.pdf sample2; date
Do 23. Mai 15:15:28 CEST 2013
Do 23. Mai 15:24:17 CEST 2013

Still not well but the best I can do for the moment!

If that's on linux use time instead of date, gives much more easy to read data :-)

thank you,Thomas Freitag.
I'll try it.

As I already figured out, the problem is the usage of scaleImage, which costs a lot of time. But now I also remembered, why I didn't use the tilingPatternFill implementation of Xpdf: Xpdf doesn't support rotated or flipped patterns very well, that's why we use drawImage.
Bringing that together, I thought about a way of avoiding the call of drawImage if possible, and I think, I found a solution. It seems to work, and it decreases dramatically the rendering speed, but it's NOT regtested.

@Albert: if You find the time to regtest it and it's okay for You, take the new patch I'll upload in a few minutes, otherwise take the already uploaded patch, please.

Created attachment 79769 [details] [review]
Try to avoid drawImage in tilingPatternFill if possible

time utils/pdftoppm -cropbox -png -r 72 -f 3 -l 3 sample2.pdf sample2

real	0m10.449s
user	0m10.153s
sys	0m0.260s

Created attachment 79794 [details]
patched splashoutputdev.cc

this is my patched splashoutputdev.cc (based your patch).

i think i corrected two mistakes in tilingPatternFill,please check if is it right?(sorry,i don't have a diffstat tool.)

(In reply to comment #7)
> Created attachment 79794 [details]
> patched splashoutputdev.cc
> 
> this is my patched splashoutputdev.cc (based your patch).
> 
> i think i corrected two mistakes in tilingPatternFill,please check if is it
> right?(sorry,i don't have a diffstat tool.)

Just use "git diff"!

Created attachment 79800 [details] [review]
patch

my patch file

Are you hijacking a bug again?

What does your patch have to do with this "very slow render" thing?

*** Bug 64963 has been marked as a duplicate of this bug. ***

Something weird is going on here, using the patch the rendering of page 35 of bug 64963 goes down from 143sec to 18sec, but for page 3 in the file in this bug it takes me around 3 minutes and not 10 seconds as you seem to have :-S

Any idea why that may be happening?

(In reply to comment #12)
> Something weird is going on here, using the patch the rendering of page 35
> of bug 64963 goes down from 143sec to 18sec, but for page 3 in the file in
> this bug it takes me around 3 minutes and not 10 seconds as you seem to have
> :-S
> 
> Any idea why that may be happening?

Seems, as if Your computer is much slower than mine:

 time utils/pdftoppm -cropbox -png -r 72 -f 35 -l 35 zgewinne\ und\ Entlastungen\ öffentlicher\ Haushalte\ durch\ Public\ Private\ Partnership\ \(PPP\).cracked.pdf zgewinne

real	0m1.099s
user	0m1.048s
sys	0m0.032s

So if I multiply my 10 seconds with 18, we get Your three minutes!

(In reply to comment #10)
> Are you hijacking a bug again?
> 
> What does your patch have to do with this "very slow render" thing?

nameX points to the fact that I forgot to call a "delete splash", that's obviously correct. The second change he made (fallback if surface_width and surface_height is too big instead of result_width and result_heigth) fits just if we can use the new algorithm. If it still uses drawImage, we still have to allocate the bigger bitmap. And because it's less likely that we run into this fallback even with the new algorithm, we can think about it if we get a PDF which fits to this case!

I'll upload a corrected patch (which also again reduces rendering time for the PDF of this bug a little bit :-) )

Created attachment 79827 [details] [review]
delete splash when no more needed

(In reply to comment #12)
> Something weird is going on here, using the patch the rendering of page 35
> of bug 64963 goes down from 143sec to 18sec, but for page 3 in the file in
> this bug it takes me around 3 minutes and not 10 seconds as you seem to have
> :-S
> 
> Any idea why that may be happening?

Can't really believe that Your computer is so much slower than mine, could it be the compiler? Can remember that there was a problem with speed in some gcc version.
I use:
gcc-Version 4.7.2 (Ubuntu/Linaro 4.7.2-2ubuntu1)

Think i found the reason, you're compiling without lcms2, right?

About the delete splash thing, is it related to this bug? can't see how

(In reply to comment #17)
> Think i found the reason, you're compiling without lcms2, right?

Oh, of course. I'm compiling without lcms at all...

> 
> About the delete splash thing, is it related to this bug? can't see how

To be honest, no, even if my tests with page 3 reduces the rendering time round about half a second. But is it really necessary to open a new bug for it? I dedicate that to You.

Just another hint, Albert (if You not already encountered it by Your own):

If You accept my patch for splash, You shouldn't close the bug but hand it over to cairo. By hazard I just opened the PDF with evince, and after it I called it with pdftocairo:

time utils/pdftocairo -cropbox -png -r 72 -f 3 -l 3 sample2.pdf sample2

real	19m49.514s
user	19m46.834s
sys	0m0.624s

!!!
(where as Bug 64963 isn't well but acceptable:

time utils/pdftocairo -cropbox -png -r 72 -f 35 -l 35 zgewinne\ und\ Entlastungen\ öffentlicher\ Haushalte\ durch\ Public\ Private\ Partnership\ \(PPP\).cracked.pdf zgewinne

real	0m23.418s
user	0m23.189s
sys	0m0.160s
)

Thomas Freitag, maybe my opinion is not thoughtful.but use "surface_width * surface_height" but "result_width * result_height",i really got 10sec on rendering page3(i5-3450,win7 64bit).

(In reply to comment #20)
> Thomas Freitag, maybe my opinion is not thoughtful.but use "surface_width *
> surface_height" but "result_width * result_height",i really got 10sec on
> rendering page3(i5-3450,win7 64bit).

What resolution did You use? As far as I tested it, the limit for this page is 280 dpi: if You render page 3 with 280 dpi, it uses the faster tilingPatternFill, if You render it with 281 dpi or higher, it uses the exact rendering of Gfx (repeat painting of the pattern).
tilingPatternFill is implemented to speed up tiling patterns where the user accept lower quality, because he probably can not see the difference when he uses a "low" resolution.
Also the tilingPatternFill costs time, the higher the resolution the bigger the bitmap which has to be "merged". You can see that in the fact that You loose "only" 10 seconds but have an exact rendering.
Perhaps the limit of 0x800000L is not the best for this PDF, but it was taken after tests with a lot of other PDF. So I don't really want to change it, but I let it up to Albert to overrule my decision.

Thomas the question about the delete line is if it belongs to the same bugfix or not. I.e. if we were not going to commit this, do we still need the delete? I understand we do, thus is part of a different bugfix.

I'll try to see why lcms is so slow, i think the lcms is being parsed all the times for the tiling

(In reply to comment #22)
> Thomas the question about the delete line is if it belongs to the same
> bugfix or not. I.e. if we were not going to commit this, do we still need
> the delete? I understand we do, thus is part of a different bugfix.

Yep. We need the delete in either case.

> 
> I'll try to see why lcms is so slow, i think the lcms is being parsed all
> the times for the tiling

Seems to be important for You before testing my patch, therefore I made some tests by my own, here my results, hopefully You come to the same conclusion:

with lcms2:

time utils/pdftoppm -cropbox -png -r 72 -f 35 -l 35 zgewinne\ und\ Entlastungen\ öffentlicher\ Haushalte\ durch\ Public\ Private\ Partnership\ \(PPP\).cracked.pdf zgewinne

real	0m16.479s
user	0m16.321s
sys	0m0.104s

(so Your computer is faster than mine :-) )

with lcms1:

time utils/pdftoppm -cropbox -png -r 72 -f 35 -l 35 zgewinne\ und\ Entlastungen\ öffentlicher\ Haushalte\ durch\ Public\ Private\ Partnership\ \(PPP\).cracked.pdf zgewinne

real	0m4.424s
user	0m4.332s
sys	0m0.056s

(that's what I expected because of the lcms discussion in the poppler community)

Then I made a valgrind profile:
We have 2639 calls of tilingPatternFill, where the tiling pattern contains an image in GfxIndexedColorSpace (parse of it is called 2639 times) which base colorspace is a GfxICCBasedColorSpace (parse of it is called 2640 times). And because this colorspace is not cached (not sure, if this is possible, I haven't looked into the PDF itself, but I can't believe that we really have 2639 different images with different colormaps), a new lcms transformation has to be constructed, and that costs the time.

Kidding: isn't that another bug, too, and You're hijacking this bug :-) ? (Okay, okay, this behaviour makes the rendering slow, too!)

(In reply to comment #23)
> Then I made a valgrind profile:
> We have 2639 calls of tilingPatternFill, where the tiling pattern contains
> an image in GfxIndexedColorSpace (parse of it is called 2639 times) ..

Sorry, that's not completely right: not the pattern contains an image, it is an imagemask in pattern colorspace, but this doesn't change my conclusion!

nameX can I have a proper name for attribution of you "delete splash;" fix?

FWIW I know how to fix the lcm slowliness problem, "just" need to find time for it :D

(In reply to comment #25)
> nameX can I have a proper name for attribution of you "delete splash;" fix?

fix is ok

(In reply to comment #27)
> (In reply to comment #25)
> > nameX can I have a proper name for attribution of you "delete splash;" fix?
> 
> fix is ok

You did not understand my question.

I want your name so i can say "Fix by XXX YYY"

Thomas "quick" question: are the 

-    if (scaledHeight < srcHeight) {
-      if (scaledWidth < srcWidth) {
+    if (scaledHeight <= srcHeight) {
+      if (scaledWidth <= srcWidth) {
        scaleImageYdXd(src, srcData, srcMode, nComps, srcAlpha,
                      srcWidth, srcHeight, scaledWidth, scaledHeight, dest);
       } else {
@@ -4077,11 +4077,11 @@ SplashBitmap *Splash::scaleImage(SplashImageSource src, void *srcData,
                      srcWidth, srcHeight, scaledWidth, scaledHeight, dest);
       }
     } else {
-      if (scaledWidth < srcWidth) {
+      if (scaledWidth <= srcWidth) {


changes needed?

If i remove them I still get the speedup and the delta with the old version renders is reduced a lot, for example, bug114741.pdf has no changes instead of changing for every page.

Created attachment 80249 [details] [review]
Move the cache up from Gfx to OutputDev

This way it gets shared when doing tiles and i get back again to the speed Thomas is having.

(In reply to comment #28)
> (In reply to comment #27)
> > (In reply to comment #25)
> > > nameX can I have a proper name for attribution of you "delete splash;" fix?
> > 
> > fix is ok
> 
> You did not understand my question.
> 
> I want your name so i can say "Fix by XXX YYY"

Li Junling

(In reply to comment #29)
> Thomas "quick" question: are the 
> 
> -    if (scaledHeight < srcHeight) {
> -      if (scaledWidth < srcWidth) {
> +    if (scaledHeight <= srcHeight) {
> +      if (scaledWidth <= srcWidth) {
>         scaleImageYdXd(src, srcData, srcMode, nComps, srcAlpha,
>                       srcWidth, srcHeight, scaledWidth, scaledHeight, dest);
>        } else {
> @@ -4077,11 +4077,11 @@ SplashBitmap *Splash::scaleImage(SplashImageSource
> src, void *srcData,
>                       srcWidth, srcHeight, scaledWidth, scaledHeight, dest);
>        }
>      } else {
> -      if (scaledWidth < srcWidth) {
> +      if (scaledWidth <= srcWidth) {
> 
> 
> changes needed?
> 
> If i remove them I still get the speedup and the delta with the old version
> renders is reduced a lot, for example, bug114741.pdf has no changes instead
> of changing for every page.


Just remove it: When I tried to find the reason for the slow rendering I thought that downscaling is faster than upscaling (at least there is definitely no bilinear interpolation), and the most pattern had the same width. But after I figured out that it didn't help really I forgot to revert it.

Thomas the speed improvements are amazing, kudos for the work!

Bad news is that amongst lots of "minor" changes i've found two changes that seem to be regressions in clipping?¿

On page 7 of bug-poppler13639.pdf, the top box of the second slide used to be totally white inside and now has some green on it

On page 464 of bug-poppler16094.pdf there is now an arrow going down from "Interrupt registers & logic" when previously it did start at the edge of the bigger box.

Do you think it's possible to solve these issues? Maybe we can filter somehow these files and let them go through the old codepath?

(In reply to comment #33)
> Thomas the speed improvements are amazing, kudos for the work!
> 
> Bad news is that amongst lots of "minor" changes i've found two changes that
> seem to be regressions in clipping?¿
> 
> On page 7 of bug-poppler13639.pdf, the top box of the second slide used to
> be totally white inside and now has some green on it

Can You compare it rendering it with 150 dpi? You'll see that the green shadow is also there with the former version. I think that with 72 dpi the pattern just wastes away. And comparing it with the other boxes: The shadows should be always there or in neither box. BTW, Acrobat on Windows doesn't show the shadows in neither box, but I'm not sure if we are just better than Acrobat or if we have some problems with transparencies. pdftocairo also doesn't show the shadows, so if You think they shouldn't be there, just open another bug, and I'll try to find the reason!

> 
> On page 464 of bug-poppler16094.pdf there is now an arrow going down from
> "Interrupt registers & logic" when previously it did start at the edge of
> the bigger box.

Same as ahead: Compare the rendering with 150 dpi, and You'll see the complete arrow also in the former version. I think that with 72 dpi the pattern just covers the thin line in the former version, and it begins to appear with 150 dpi. Acrobat on Windows doesn't show the line in the bigger box, even if I zoom it very high, but this time I think we ARE better: The line makes sense, instead of pointing just from the bigger box to "Interrupt Mapper", the arrow from "Interrupt registers & logic" to "Interrupt Mapper" makes much more sense.
But I must admit that once again pdftocairo doesn't show it either. Perhaps patterns should not have any transparencies? I'm not sure...

> 
> Do you think it's possible to solve these issues? Maybe we can filter
> somehow these files and let them go through the old codepath?

At least with bug-poppler16094.pdf I see no way to distinguish it: The scaling of the (pattern) images should not be done anyway. A

fprintf(stderr, "%d x %d => %d x %d\n", srcWidth, srcHeight, scaledWidth, scaledHeight);

in Splash::scaleImage gives:

698 x 268 => 698 x 268
450 x 320 => 450 x 320
498 x 320 => 498 x 320
22 x 24 => 22 x 24
22 x 24 => 22 x 24

Ok, I've commited Thomas patch.

Changing the component to Cairo output since with the cairo output it's still slow (at at least page 35 of bug-poppler64963.pdf is also wrong

-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/poppler/poppler/issues/267.