| Summary: | Dynamic memory usage limit doesn't take into account virtual memory exhaustion | ||
|---|---|---|---|
| Product: | [Applications] okular | Reporter: | Martin M <martin.cg.magnusson> |
| Component: | general | Assignee: | Okular developers <okular-devel> |
| Status: | CONFIRMED --- | ||
| Severity: | crash | CC: | aacid, fabiodurso, justin.zobel, postix |
| Priority: | NOR | ||
| Version First Reported In: | 0.16.2 | ||
| Target Milestone: | --- | ||
| Platform: | Ubuntu | ||
| OS: | Linux | ||
| Latest Commit: | Version Fixed In: | ||
| Sentry Crash Report: | |||
| Attachments: |
valgrind pdftoppm output
My full valgrind pdf2ppm output Valgrind output of okular on the problem file Valgrind output with okular-dbg installed Valgrind output without searching |
||
|
Description
Martin M
2013-06-05 06:44:52 UTC
You sure it's related to searching? The backtrace seems to imply it's crashing on just rendering? Can you make it crash by just navigating all the pages of the document? Yes, now I see that I can make it crash just by navigating. Scrolling through the document,pressing page down and page up, (while it is being loaded in the background, I assume) also crashes Okular after a while. Can you please attach the document? Sure. The file is too large to attach, but here's a dropbox link to it https://www.dropbox.com/s/n3k4vdplmceagkt/ICRA-2013-Digest.pdf No crash here by just scrolling (Fedora x86 32-bit, poppler 0.20.2 with lots of backported patches). What is your Poppler version (pdfinfo -v)? You said it also crashes if you search some text, what text exactly? Can you please run "kdebugdialog", enable all okular entries and run okular from the shell? After opening the document you'll see lots of debug output. Just before the crash you should see something like: okular(18020)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 223x315@64 async == true isTile == false Can you paste that line? (the number after @ is the zero-based page on which the crash is happening) Thank you. I tried running from the command line as you suggested. This time it was harder to provoke a crash. I scrolled up and down through the document a few times, and it worked OK. I also did a few searches, and it worked OK. Finally, I searched for "navigation" a few times, and then it crashed. The lines you asked for are pasted here: okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@189 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@188 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@191 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@187 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@192 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@194 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@195 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@197 async == true isTile == false okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@181 async == true isTile == false I also get a ton of lines (a few thousand) like: okular(19505)/okular (app) Okular::Document::requestPixmaps: request id=3 651x922@270 with different page numbers at the end I have pdfinfo version 0.20.5 Tried with poppler 0.20.5, still no crash here :/ Yes, lines like okular(19505)/okular (app) Okular::Document::requestPixmaps: request id=3 651x922@270 list all pending requests, which are then processed sequentially. Lines like okular(19505)/okular (app) Okular::DocumentPrivate::sendGeneratorPixmapRequest: sending request id=3 1532x2167@181 async == true isTile == false tell what's actually being processed right now (in this case a 1532x2167 rendering of page 182). I can see that page, and I see you've added annotations on it, so you see it too. It seems this bug doesn't happen always. Let's wait to see if someone else manages to reproduce it. I've also searched for "navigation", and it reaches the end of the document without any issue. @Albert: In the meantime I'm running pdftoppm on each page through valgrind memcheck. Created attachment 80346 [details]
valgrind pdftoppm output
As said, I've run
seq 1 273 | while read X; do echo pdftoppm -f $X -l $X ICRA-2013-Digest.pdf; valgrind pdftoppm -f $X -l $X ICRA-2013-Digest.pdf > /dev/null; done
I'm attaching the output (I've removed output for pages that produced no errors).
Note: pdftoppm is poppler 0.20.5
I don't see anything that can cause a crash.
bugzilla@eyra.se can you run same command than Fabio and attach the output? @Fabio: Well the uninitialized values are never cool, if they happen in an if they can make the code do weird stuff Created attachment 80385 [details]
My full valgrind pdf2ppm output
Generated with
seq 1 273 | while read X; do echo pdftoppm -f $X -l $X ICRA-2013-Digest.pdf >> valgrind-output; nice valgrind pdftoppm -f $X -l $X ICRA-2013-Digest.pdf 2>> valgrind-output > /dev/null; done
Ok, so the same uninitialzed values than Fabio gets, as a last thing, can you plese run valgrind okular myfile.pdf try to go to the file that causes the crash and also attach the output? Created attachment 80400 [details]
Valgrind output of okular on the problem file
Here's the command line I used:
valgrind okular ICRA-2013-Digest.pdf 2>valgrind-okular-output
What I did was to open the file and search for "navigation" a few times, until it crashed.
So it seems it's not Poppler's fault. Weird.... QPainter::begin: Paint device returned engine == 0, type: 3 QPainter::end: Painter not active, aborted It might be something bad happening in the PagePainter class, but it's a hard to say what's going on in that stack trace full of ???s, maybe installing okular-dbg can help. bugzilla@eyra.se: Can you confirm every time it crashes you first get this QPainter::begin: Paint device returned engine == 0, type: 3 QPainter::end: Painter not active, aborted Thing? Created attachment 80417 [details]
Valgrind output with okular-dbg installed
I installed okular-dbg and reran
valgrind okular ICRA-2013-Digest.pdf 2>valgrind-okular-output2
Again, I searched for "navigation" until Okular crashed, which was at some point after page 83. However, the reason for the crash this time seems to be that valgrind ran out of memory. I have 16 GB RAM, but run 32-bit Kubuntu with PAE. I don't see any "Painter not active" messages this time.
(In reply to comment #15) > However, the reason for the crash this time seems to be > that valgrind ran out of memory. I have 16 GB RAM, but run 32-bit Kubuntu > with PAE. I don't see any "Painter not active" messages this time. Makes sense, the algorithm that decides when to stop allocating only looks at the amount of physical memory, and it ignores the fact that you can't allocate more than 3GB under 32-bit linux. @Albert: In the light of this, the "QPainter::begin: Paint device returned engine == 0, type: 3" might be a result of a failed allocation too, what do you think? A failed new is supposed to throw an exception instead of returning NULL, but it's possible that Qt is using plain malloc or nothrow new somewhere. I just tried to run the same thing again, and now I was able to search through the document until okular asked if I wanted to continue from the beginning. The difference this time was that I waited long enough to let the whole document load before starting to search (I have the "greedy" performance setting, so it reads in all the pages in the background). No valgrind crash, and no okular crash. (Thanks a lot for all your help, by the way!) Created attachment 80421 [details]
Valgrind output without searching
Maybe the problem also has to do with which monitor output I am using.
The attached log is the output from valgrind when just opening the document and let it sit and load all the pages, without searching. I just ran
valgrind okular ICRA-2013-Digest.pdf 2>valgrind-okular-output5
and went for lunch, and this crash report is what I had when I came back.
This time, the okular window was at my laptop screen, which is 1920x1080. Last time, when I didn't get a crash, the window was open on the external VGA monitor, which is 1280x1024.
Yes, that's surely what makes the difference between a crash or not. I've done some calculations. On your 1920x1080 monitor each page is 1532x2167 pixels (according to the last log you posted). Since images are stored as ARGB that makes for 1532x2167x4 = 13,2 MB per page. 13,2 MB x 273 pages = 3,6 GB, which is above the 3 GB virtual memory limit. Indeed, this last stack trace is Poppler failing to allocate memory. I don't know how big images are on your 1280x1024 monitor because I have no logs. Assuming that page size is proportional to monitor width, the total memory usage would be: 3,6 GB x ( 1280 / 1920 )^2 = 1.6 GB, which is well below the 3 GB barrier. Feel free to post a log on your 1280x1024 monitor (no need to use valgrind) to confirm/deny my calculations. So it makes sense that we don't go out out of memory on your 1280x1024 monitor, whereas we do on the 1920x1080 one. To sum up, we have this bug: Our dynamic memory usage limit doesn't take into account virtual memory exhaustion. (In reply to comment #17) > (Thanks a lot for all your help, by the way!) Thank you for caring about okular! :D The image sizes on the 1280x1024 monitor is 1017x1439 pixels, according to the output below okular(12441)/okular (app) Okular::Document::requestPixmaps: request id=3 1017x1439@272 So that would mean 5.8 MB/page, and indeed 1.6 GB for the whole document. Running htop tells me that okular uses 1662 MB virtual memory and 1555 MB res memory. Martin, do you still have this setup? We have a patch that may or may not fix this but since none of us have a similar setup to yours we can't confirm it fixes it or not. Also would you be able to compile okular with a patch we provide you? I have almost the same setup, but Okular has been updated to 0.16.5. And yes, I can compile a patched Okular. So if you send the patch I'd be happy to try it. Actually can you save this
#include <sys/time.h>
#include <sys/resource.h>
#include <stdio.h>
int main(int argc, char *argv[])
{
struct rlimit rlim;
int res = getrlimit(RLIMIT_AS, &rlim);
printf("%d %lu %lu\n", res, rlim.rlim_cur, rlim.rlim_max);
}
to a file named main.cppp and run
g++ main.cpp
./a.out
And attach the output?
Sure. The output is: 0 4294967295 4294967295 Is that good? Well, it means your maximum allocation in a single program it's 4GB, is that correct for your setup? Yes, that should be correct. I have 16 GB RAM and I am running a 32-bit PAE kernel. Great that is good. Now I only need some time to code this properly :) (In reply to Albert Astals Cid from comment #27) > Great that is good. Now I only need some time to code this properly :) Hey Albert, did this end up being coded and pushed to okular? I don't remember, i don't think so. |