Bug#514542: okular: runs open() and stat64() 632 times on certain files in home directory

[Arthur Marsh <arthur.marsh@internode.on.net>]

Pino Toscano wrote, on 13/04/09 22:37:
> Version: 4:4.1.0-3
> thanks
>
> Hi Arthur,
>
> > I was trying to find out why okular what slow to start up and ran strace
> > on it. I found that even though okular was run from a directory other
> > than my home directory, for files whose extension was not a known mime
> > type, open() was called followed by stat64() being called 632 times per
> > file open()'d:
> > [...]
>
> I see you are an user of unstable; could you test again now that there are 
> more updated versions of kde4libs and okular?
>
> Thanks,

Hi, I re-ran okular 4:4.2.2-1 from strace with output directed to 
okular.log and obtained:

$ grep open okular.log|wc -l
893
amarsh04@victoria:~$ grep stat64 okular.log|wc -l
4392
amarsh04@victoria:~$ grep kdebug.areas okular.log|wc -l
739
amarsh04@victoria:~$

This was without opening any files within okular.

The kdebug.areas access seems puzzling:

$ grep kdebug.areas okular.log|head
access("/home/amarsh04/.kde/share/config/kdebug.areas", R_OK) = -1 
ENOENT (No such file or directory)
access("/etc/kde4/kdebug.areas", R_OK)  = -1 ENOENT (No such file or 
directory)
access("/usr/share/kde4/config/kdebug.areas", R_OK) = 0
stat64("/usr/share/kde4/config/kdebug.areas", {st_mode=S_IFREG|0644, 
st_size=19220, ...}) = 0
open("/usr/share/kde4/config/kdebug.areas", O_RDONLY|O_LARGEFILE) = 10
stat64("/usr/share/kde4/config/kdebug.areas", {st_mode=S_IFREG|0644, 
st_size=19220, ...}) = 0
stat64("/usr/share/kde4/config/kdebug.areas", {st_mode=S_IFREG|0644, 
st_size=19220, ...}) = 0
stat64("/usr/share/kde4/config/kdebug.areas", {st_mode=S_IFREG|0644, 
st_size=19220, ...}) = 0
stat64("/usr/share/kde4/config/kdebug.areas", {st_mode=S_IFREG|0644, 
st_size=19220, ...}) = 0
stat64("/usr/share/kde4/config/kdebug.areas", {st_mode=S_IFREG|0644, 
st_size=19220, ...}) = 0

All the remaining stat64 calls on kdebug.areas appear the same.

Is this a case of code being used for debugging, and rather than read 
kdebug.areas once and store the data in okular, it is re-read hundreds 
of times?

I re-ran okular under strace logging output to okular2.log:

amarsh04@victoria:~$ grep open okular2.log|wc -l
498
amarsh04@victoria:~$ grep stat64 okular2.log|wc -l
2538
amarsh04@victoria:~$ grep kdebug.areas okular2.log|wc -l
739
amarsh04@victoria:~$ grep stat64 okular2.log|sort -u|wc -l
656

It does not seem as slow running on second and subsequent times but 
still seems to perform a very large number of file accesses on startup.

Regards,

Arthur.