Bug 78006

Summary: Certain documents take ages to open
Product: poppler Reporter: octoploid <octoploid>
Component: generalAssignee: poppler-bugs <poppler-bugs>
Status: RESOLVED MOVED QA Contact:
Severity: normal    
Priority: medium CC: octoploid
Version: unspecified   
Hardware: Other   
OS: All   
URL: https://bugs.kde.org/show_bug.cgi?id=333999
Whiteboard:
i915 platform: i915 features:

Description octoploid 2014-04-27 14:45:07 UTC
Certain pdf documents take very long before they are displayed
in okular. For example the attached file take over 6 seconds.
strace shows endless stream of:
...
pread(10, "49424 0 obj\n<<\n/Type/ObjStm\n/N 2"..., 256, 3529694) = 256
pread(10, "\nendstream\nendobj\n49425 0 obj\n<<"..., 256, 3532260) = 256
pread(10, "x\332\225\231K\226\305(\16D\347\275\n\257\300\315G\10\330F\217\352sz\7uzV\373\257\33\274"..., 256, 3529784) = 256
pread(10, ";&01\272\236\246L\24\272\242N\34\322\221s%\4\204\236\241y\345\23\231\2773\373\327Sv\235"..., 256, 3530040) = 256
pread(10, "Z\25\224A\24&\253B\317'qJe!\30i\31i\312\300f`\260\253\274\264\213\27\302\\\306:"..., 256, 3530296) = 256
pread(10, "EZ\300\250\214\372\32\330Q}\365\27vD\246\257\364\223\351\1\240\34B\3435k/D\21\317\"\312"..., 256, 3530552) = 256
pread(10, "\244\313\251\322\245K\235@0$\307\2\"\236ur, \"\233!\276\200(-\265AuAO\305}"..., 256, 3530808) = 256
pread(10, " \373\2\0|B^\337\vj\362\217\264\363\211\351\177\273\270W\343\331f\344\244Q\227\254V?\363;"..., 256, 3531064) = 256
pread(10, "\221\21k,[U\2055r\211~\341\n\371\\\317\360NlBB7Z\312\266\220V\266\205\21e\274"..., 256, 3531320) = 256
pread(10, "\374\32<\244~\206v\234\324/U]\342\322\315\265\224\366\327\363\2467w\212\224\313B\254MWL\33"..., 256, 3531576) = 256
pread(10, "\33\345\262M\233\256\312\205\207\223\235\356\224\313\311PyR\256\262\34\265\357\244\t\212\230\215\341\2354m"..., 256, 3531832) = 256
pread(10, "\177\345K\255,\252\\R\211?\337B\334)\337v}t\247|\272\204\311O\312\27\333\31~<\220\31"..., 172, 3532088) = 172
pread(10, "49559 0 obj\n<<\n/Type/ObjStm\n/N 2"..., 256, 3878926) = 256
pread(10, "\nendstream\nendobj\n49560 0 obj\n<<"..., 256, 3881527) = 256
pread(10, "x\332\225X[\262\335&\20\374\317*\264\2\2\363\2\266\221\257<*;p\345/\373O7\327\26\10"..., 256, 3879016) = 256
pread(10, "H\274\32\361mx\f\261\26\6\30\201(\232\241\245CM\25b\317\343iP\344\351E;Ee\200L"..., 256, 3879272) = 256
pread(10, "\340)\337C\230\300\34\246\0248\1H\341\204\r\240P\201\307 #x1\263@\200@\241C\213\10\201"..., 256, 3879528) = 256
pread(10, "A\204s\3\27\330f\254;\324:^\201\3764\300\0s\f\320#\30\360\"\207\307\4\3{\22\335\316"..., 256, 3879784) = 256
pread(10, "\v\234\300\240\22\f\24\331\306\1\206~`\372\225\1\6\f\313l_\0100\210\365\v\1\30\234_S\205"..., 256, 3880040) = 256
pread(10, "n\322o\31\17\317\251\237\356\243W\356\36\240\31\244~\276B\375Z\256.-\371\231s\220\300Y\256\0"..., 256, 3880296) = 256
pread(10, "[\17\20\224\327t0\310\365\317\2Dmb\304a\210$;\223\33\34\374k\357\5\202\3624n\255\215"..., 256, 3880552) = 256
pread(10, "\23\373\302\245+\265\271\335o\333+z\350\354\335\240X\376\377)\226U\264\247x\241X\227\n}\342X"..., 256, 3880808) = 256
pread(10, "\237L\206\37:V\220\206/\\\345\211\10\225\225\343\336\250\216\240\21\224O\253\344\307\263\256\236\230\f."..., 256, 3881064) = 256
pread(10, "\223\34\223\222^?\25e\24p}\3418\245\267\345\252\372\300q\2500i\270mM\306Q\240\23\304O"..., 207, 3881320) = 207
pread(10, "49498 0 obj\n<<\n/Type/ObjStm\n/N 2"..., 256, 3721754) = 256
pread(10, "\nendstream\nendobj\n49499 0 obj\n<<"..., 256, 3724334) = 256
...
Comment 1 octoploid 2014-04-27 14:49:10 UTC
The file is too big (~4MB), you can download it here:
http://trippelsdorf.de/c++14-std.pdf
Comment 2 octoploid 2014-04-27 16:44:31 UTC
Callgrind shows:

--------------------------------------------------------------------------------
           Ir  file:function
--------------------------------------------------------------------------------
4,836,050,329  ???:inflate [/lib64/libz.so.1.2.8]
2,447,514,148  ???:Lexer::getObj(Object*, int) [/usr/lib64/libpoppler.so.44.0.0]
2,423,242,583  ???:Lexer::getChar(bool) [/usr/lib64/libpoppler.so.44.0.0]
1,930,117,398  ???:_int_malloc [/lib64/libc-2.19.so]
1,817,056,786  ???:_int_free [/lib64/libc-2.19.so]
1,104,522,639  ???:pthread_mutex_lock [/lib64/libc-2.19.so]
  986,351,514  ???:adler32 [/lib64/libz.so.1.2.8]
  970,140,091  ???:FlateStream::fill_buffer() [/usr/lib64/libpoppler.so.44.0.0]
  929,653,000  ???:updatewindow [/lib64/libz.so.1.2.8]
  926,941,897  ???:malloc [/lib64/ld-2.19.so]
  888,739,879  ???:FlateStream::getRawChar() [/usr/lib64/libpoppler.so.44.0.0]
  819,731,562  ???:EmbedStream::getChar() [/usr/lib64/libpoppler.so.44.0.0]
  796,210,919  ???:__pthread_mutex_unlock_usercnt [/lib64/libpthread-2.19.so]
  755,289,360  ???:Lexer::lookChar() [/usr/lib64/libpoppler.so.44.0.0]
  504,252,637  ???:Parser::shift(int) [/usr/lib64/libpoppler.so.44.0.0]
  502,636,507  ???:Object::free() [/usr/lib64/libpoppler.so.44.0.0]
  474,337,628  ???:Parser::getObj(Object*, bool, unsigned char*, CryptAlgorithm, int, int, int, int, bool)'2 [/usr/lib64/libpoppler.so.44.0.0]
  444,389,766  ???:FlateStream::getChar() [/usr/lib64/libpoppler.so.44.0.0]
  414,240,772  ???:Parser::getObj(Object*, bool, unsigned char*, CryptAlgorithm, int, int, int, int, bool) [/usr/lib64/libpoppler.so.44.0.0]
  408,932,209  ???:memcpy@@GLIBC_2.14 [/lib64/libc-2.19.so]
  339,606,073  ???:free [/lib64/ld-2.19.so]
  267,088,262  ???:strcpy [/lib64/libc-2.19.so]
  236,291,915  ???:Array::add(Object*) [/usr/lib64/libpoppler.so.44.0.0]
  231,210,549  ???:pthread_mutex_unlock [/lib64/libc-2.19.so]
  201,569,086  ???:FileStream::getChar() [/usr/lib64/libpoppler.so.44.0.0]
  189,403,722  ???:malloc_consolidate [/lib64/libc-2.19.so]
  185,936,494  ???:ObjectStream::ObjectStream(XRef*, int, int) [/usr/lib64/libpoppler.so.44.0.0]
  168,983,450  ???:strlen [/lib64/ld-2.19.so]
  167,231,238  ???:pthread_mutex_init [/lib64/libc-2.19.so]
  161,358,915  ???:Object::free()'2 [/usr/lib64/libpoppler.so.44.0.0]
  122,569,308  ???:Catalog::getPageRef(int) [/usr/lib64/libpoppler.so.44.0.0]
  121,367,371  ???:copyString [/usr/lib64/libpoppler.so.44.0.0]
  118,516,078  ???:Array::~Array() [/usr/lib64/libpoppler.so.44.0.0]
  118,085,870  ???:Catalog::getNumPages() [/usr/lib64/libpoppler.so.44.0.0]
   99,507,532  ???:operator new(unsigned long) [/usr/lib64/gcc/x86_64-pc-linux-gnu/4.9.1/libstdc++.so.6.0.20]
   98,522,904  ???:inflate_table [/lib64/libz.so.1.2.8]
   90,815,198  ???:strcmp [/lib64/ld-2.19.so]
   86,916,246  ???:greallocn [/usr/lib64/libpoppler.so.44.0.0]
   84,038,778  ???:gmalloc [/usr/lib64/libpoppler.so.44.0.0]
   80,091,374  ???:Splash::compositeBackground(unsigned char*) [/usr/lib64/libpoppler.so.44.0.0]
...
Comment 3 Thomas Freitag 2014-04-28 08:07:07 UTC
The referenced document has 1385 pages. Rendering of 1 page in default resolution takes on my laptop:

time ./utils/pdftoppm -png -cropbox -f 1 -l 1 78006.open/c++14-std.pdf output/78006

real	0m0.227s
user	0m0.204s
sys	0m0.008s

Rendering of 10 pages:

time ./utils/pdftoppm -png -cropbox -f 1 -l 10 78006.open/c++14-std.pdf output/78006

real	0m3.366s
user	0m3.340s
sys	0m0.008s

I think I'm getting too old if someone argues that it "takes ages to open". But even if, it's definitely not a poppler problem but a problem of the application which opens it!
Comment 4 octoploid 2014-04-28 09:06:44 UTC
OK thanks. I will open a okular bug.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.