Bug 52551 - testpage takes over one minute to open with Okular
Summary: testpage takes over one minute to open with Okular
Status: RESOLVED MOVED
Alias: None
Product: poppler
Classification: Unclassified
Component: general (show other bugs)
Version: unspecified
Hardware: Other All
: medium normal
Assignee: poppler-bugs
QA Contact:
URL: http://sourceware.org/bugzilla/show_b...
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-07-26 14:58 UTC by Octoploid
Modified: 2012-08-03 05:10 UTC (History)
0 users

See Also:
i915 platform:
i915 features:


Attachments
testpage (2.87 MB, application/x-www-form-urlencoded)
2012-07-26 14:58 UTC, Octoploid
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Octoploid 2012-07-26 14:58:41 UTC
Created attachment 64743 [details]
testpage

The attached testpage takes over one minute of CPU-time before 
it is rendered to the screen when I open it with Okular.
Comment 1 Octoploid 2012-07-26 15:13:55 UTC
# ========
# captured on: Thu Jul 26 17:07:51 2012
# hostname : x4
# os release : 3.5.0-04773-gbdc0077-dirty
# perf version : 3.5.rc6.40.g055c9f.dirty
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : AMD Phenom(tm) II X4 955 Processor
# cpuid : AuthenticAMD,16,4,2
# total memory : 8169156 kB
# cmdline : /usr/src/linux/tools/perf/perf record okular testpage.pdf
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, id = { 65, 66, 67, 68 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# ========
#
# Samples: 248K of event 'cycles'
# Event count (approx.): 199556998272
#
# Overhead  Command  Shared Object            Symbol

    35.90%   okular  libm-2.16.so             [.] feraiseexcept
    12.30%   okular  libm-2.16.so             [.] __sin
     9.03%   okular  libm-2.16.so             [.] __cos
     5.01%   okular  libpoppler.so.26.0.0     [.] void std::__introsort_loop<SplashIntersect*, long, cmpIntersectFunctor>(SplashIntersect*, SplashInt
ersect*, long, cmpIntersectFunctor)
     2.80%   okular  libpoppler.so.26.0.0     [.] SplashXPathScanner::computeIntersections()
     2.62%   okular  libc-2.16.so             [.] _int_malloc
     2.57%   okular  libm-2.16.so             [.] __dubsin
     2.29%   okular  libpoppler.so.26.0.0     [.] SplashXPathScanner::addIntersection(double, double, unsigned int, int, int, int)
     2.14%   okular  libpoppler.so.26.0.0     [.] void std::__unguarded_linear_insert<SplashIntersect*, cmpIntersectFunctor>(SplashIntersect*, cmpInt
ersectFunctor)
     1.41%   okular  libpoppler.so.26.0.0     [.] Lexer::getObj(Object*, int)
     1.35%   okular  libpoppler.so.26.0.0     [.] Gfx::doRadialShFill(GfxRadialShading*)
     1.35%   okular  libc-2.16.so             [.] _int_free
     1.11%   okular  libpoppler.so.26.0.0     [.] void std::__adjust_heap<SplashIntersect*, long, SplashIntersect, cmpIntersectFunctor>(SplashInterse
ct*, long, long, SplashIntersect, cmpIntersectFunctor)
     1.09%   okular  libpoppler.so.26.0.0     [.] Lexer::getChar(bool)
     0.90%   okular  libpoppler.so.26.0.0     [.] GfxSubpath::lineTo(double, double)
     0.88%   okular  libm-2.16.so             [.] __sincos
     0.82%   okular  libz.so.1.2.7            [.] inflate
Comment 2 Octoploid 2012-07-26 21:10:56 UTC
It looks like a bug in glibc-2.16. Before commit b35fe25ed (of glibc) it takes 24 seconds:

# Overhead      Command  Shared Object            Symbol
    24.09%       okular  libm.so                  [.] __sincos
    10.42%       okular  libpoppler.so.26.0.0     [.] SplashIntersect* std::__unguarded_partition<SplashIntersect*, SplashIntersect, cmpIntersectFunc
tor>(SplashIntersect*, SplashIntersect*, SplashIntersect const&, cmpIntersectFunctor)
     5.73%       okular  libpoppler.so.26.0.0     [.] SplashXPathScanner::computeIntersections()
     5.13%       okular  libpoppler.so.26.0.0     [.] void std::__unguarded_linear_insert<SplashIntersect*, cmpIntersectFunctor>(SplashIntersect*, cmpIntersectFunctor)
     4.87%       okular  libpoppler.so.26.0.0     [.] SplashXPathScanner::addIntersection(double, double, unsigned int, int, int, int)
     4.39%       okular  libc-2.16.90.so          [.] _int_malloc
     3.65%       okular  libpoppler.so.26.0.0     [.] void std::__adjust_heap<SplashIntersect*, long, SplashIntersect, cmpIntersectFunctor>(SplashInt
ersect*, long, long, SplashIntersect, cmpIntersectFunctor)
Comment 3 Albert Astals Cid 2012-08-01 21:39:44 UTC
Takes 16 seconds here, not over a minute, anyway, it is a comple file and thus it takes time to render, of course it can be probably improved, but we have much other things to do other than optimizing for complex files like these.

BTW you should open a bug against the glibc devels if they have such a massive regression in performance.
Comment 4 Octoploid 2012-08-02 02:44:44 UTC
(In reply to comment #3)
> Takes 16 seconds here, not over a minute, anyway, it is a comple file and thus
> it takes time to render, of course it can be probably improved, but we have
> much other things to do other than optimizing for complex files like these.

One way of improving the issue would be to display text first and render complex graphics in the background (like Acrobat Reader).

> BTW you should open a bug against the glibc devels if they have such a massive
> regression in performance.

I already did that see URL in the summary:
http://sourceware.org/bugzilla/show_bug.cgi?id=14412
Comment 5 Octoploid 2012-08-03 05:10:40 UTC
Moved to glibc.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct.