Find out why program is slow processing files from network share using Valgrind

Question

I have an open source C/C++ program on Linux amd64 that processes a PDF input file and that I did not write by myself. So I'm not familiar with its code.

• Processing a PDF file read from local disk runs within 1-2 seconds using the program.
• But when I have it process the same file from a mounted Samba share, it takes minutes to complete.
• Firefox opens and renders the same PDF from the Samba share within about 2-3 seconds.

I've already ruled out the hypothesis my Samba setup being that slow in general because the performance of other applications is fine, including Firefox, LibreOffice and things like cp or sha1sum reading files from the share very quickly.

It must be something in the C/C++ program that maybe suffers seriously from the high latency, maybe because it causes a Samba server roundtrip for every single byte or whatever.

I've run

valgrind --tool=callgrind ./myprogram /sambasrv/share/myfile.pdf

and tried to interpret its output with kcachegrind.

But nothing special caught my eye. I would have expected a certain call to be huge where it spends all the time waiting for the network. But maybe I'm looking at the wrong things.

How would you investigate in what method all the execution time of about a minute is spent?

Unfortunately, I haven't used Valgrind until today. So please excuse my newbie question.

• MrSnrub: @KJ I don't modify the PDF file and I do not read it over and over again. The problem I'm facing is: myprogram ~/test.pdf runs in 1-2 seconds, while myprogram /sambasrv/share/myfile.pdf with exactly the same file takes minutes, although cp /sambasrv/share/myfile.pdf ~/localstorage/ runs in a second as well. Now I want to find out why the program performs that differently on local opposed to Samba network storage. I want to see where the performance penalty of about 1 minute is spent/comes from so I could improve the program.

Answer 1

By default, callgrind will only capture instructions being executed. If you want to look at the time taken by system call, you should add the following option;

 --collect-systime=no|yes|msec|usec|nsec Collect system call time info? [no]
 no Do not collect system call time info.
 msec|yes Collect syscount, syscall elapsed time (milli-seconds).
 usec Collect syscount, syscall elapsed time (micro-seconds).
 nsec Collect syscount, syscall elapsed and syscall cpu time (nano-seconds).

If you do not specify it, the default value for this option is "no" (as indicated at the end of the first line).

Once you have selected the above, kcachegrind will allow you to look at system calls related information such as elapsed time spent in the system call.