Re: Severe performance degradation on Linux
On 2015-01-10 10:18 PM, Michael Meeks wrote: On Sat, 2015-01-10 at 16:08 +0200, Noel Grandin wrote: we should probably turn this on automatically for localhost connections. Sounds eminently sensible - a patch ? =) https://gerrit.libreoffice.org/#/c/13856/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Thank you everybody for poking this problem. After much discussion in different places I was able to resolve this: set the TCP_NODELAY flag when setting up the connection on both sides. By passing the following string: uno:socket,host=localhost,port=2002,tcpNoDelay=1 when creating both the Office instance and the client side, the test document ran for about 0.9 seconds (instead of 45s) at almost the speed of the named pipe. More info about this is here: https://superuser.com/questions/860321/linux-localhost-sockets-painfully-slower-than-on-mac/862303 Cheers, Jens -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hrm. I thought I tried that, but I see my mistake now: I didnt set 'tcpNoDelay=1 on *both* ends. Looks like Noel Grandin was right after all. Oh, well.. At least I learned some more details on how to read and interpret strace output in the process. ;) - Maarten On Sat, Jan 10, 2015 at 3:01 PM, Jens Tröger jens.troe...@light-speed.de wrote: Thank you everybody for poking this problem. After much discussion in different places I was able to resolve this: set the TCP_NODELAY flag when setting up the connection on both sides. By passing the following string: uno:socket,host=localhost,port=2002,tcpNoDelay=1 when creating both the Office instance and the client side, the test document ran for about 0.9 seconds (instead of 45s) at almost the speed of the named pipe. More info about this is here: https://superuser.com/questions/860321/linux-localhost-sockets-painfully-slower-than-on-mac/862303 Cheers, Jens -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
we should probably turn this on automatically for localhost connections. ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On Sat, 2015-01-10 at 16:08 +0200, Noel Grandin wrote: we should probably turn this on automatically for localhost connections. Sounds eminently sensible - a patch ? =) ATB, Michael. -- michael.me...@collabora.com , Pseudo Engineer, itinerant idiot ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hrm. Two more things I noticed, though again Im not sure how relevant those are, it's probably nothing : In one thread/pid (3986), I see about 300 occurances of '... poll resumed ) = 0 (Timeout)', and in the entire output (again thread/pid 3986, among others) there are about 1100 lines of 'EAGAIN (Resource temporarily unavailable)'. I attached the excerpt of that thread/pid. - Maarten strace.log.3986.txt.gz Description: GNU Zip compressed data ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, On Wed, Jan 7, 2015 at 3:17 PM, Markus Mohrhard markus.mohrh...@googlemail.com wrote: Ah. I fear that this is a regression introduced through my code. This sounds a bit like the glxtest codewhich might not work optimally in a headless setup. I suppose you are using 4-4 or master. Regards, Markus I can reproduce the issue with (at least, didnt try any others) LibreOffice 4.2.7.2 (Ubuntu 14.04), LibreOffice 4.3.4.1 (Fedora 21), and master. - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, On Wed, Jan 7, 2015 at 10:27 AM, Michael Meeks michael.me...@collabora.com wrote: Anyhow - hopefully that gives some pointers that you can puzzle through try to trace / chase down what's going wrong for you. Thanks for that very elaborate investigation, and for taking the time to explain the research. Even if it doesnt help to solve the issue, at least it has been very informative for me. Ill give the trace another look. - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi Maarten,
On Wed, 2015-01-07 at 09:21 +0100, Maarten Hoes wrote:
Two more things I noticed, though again Im not sure how relevant those
are, it's probably nothing :
So the thing you're looking for looks often like this:
3986 1420550762.879658 poll([{fd=6, events=POLLIN}], 1, 4294967295 unfinished
...
3986 1420550767.916824 ... poll resumed ) = 1 ([{fd=6, revents=POLLIN}])
Which is from your log; the poll that timed out just before it is
~irrelevant we tend to do a zero timeout (non-blocking) poll before we
do a blocking one for one reason and another - ignore that.
The question is - what is this fd 6 we are polling on - I searched
backwards in your log for ') = 6$' and got:
3986 1420550762.752026
open(/home/buildslave/source/libo-core/instdir/program/../program/bootstraprc,
O_RDONLY|O_EXCL unfinished ...
3986 1420550762.752085 ... open resumed ) = 6
Which is nonsense - since we immediately close that fd again. So then I
looked for socket = and pipe:
3986 1420550762.753764 pipe( unfinished ...
3986 1420550762.753808 ... pipe resumed [6, 7]) = 0
Which seems to be in this context:
3986 1420550762.753207
lstat(/home/buildslave/source/libo-core/instdir/program,
{st_mode=S_IFDIR|0775, st_size=20480, ...}) = 0
3986 1420550762.753235
lstat(/home/buildslave/source/libo-core/instdir/program/libvcllo.so,
{st_mode=S_IFREG|0775, st_size=8609416, ...}) = 0
3986 1420550762.753259 futex(0x7f160b8d50c8, FUTEX_WAKE_PRIVATE, 2147483647
unfinished ...
3986 1420550762.753285 ... futex resumed ) = 0
3986 1420550762.753764 pipe( unfinished ...
3986 1420550762.753808 ... pipe resumed [6, 7]) = 0
3986 1420550762.753829 fcntl(6, F_GETFD) = 0
3986 1420550762.753867 fcntl(6, F_SETFD, FD_CLOEXEC) = 0
3986 1420550762.753885 fcntl(7, F_GETFD unfinished ...
3986 1420550762.753930 ... fcntl resumed ) = 0
3986 1420550762.753945 fcntl(7, F_SETFD, FD_CLOEXEC) = 0
3986 1420550762.753978 fcntl(6, F_GETFL) = 0 (flags O_RDONLY)
3986 1420550762.754003 fcntl(6, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
3986 1420550762.754028 fcntl(7, F_GETFL) = 0x1 (flags O_WRONLY)
3986 1420550762.754038 fcntl(7, F_SETFL, O_WRONLY|O_NONBLOCK unfinished ...
Which looks like a reasonably normal pipe setup - but - I wonder what
it's for =) I imagine to communicate with:
3986 1420550762.809356 clone(child_stack=0x7f15f2372eb0,
flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID,
parent_tidptr=0x7f15f23739d0, tls=0x7f15f2373700, child_tidptr=0x7f15f23739d0)
= 3989
Whatever is 'execve'd from that fork - unfortunately I don't see the -f
strace output there - to be able to follow that. Something (prolly vcl)
spawns something - and we block for 5 seconds on the output of that.
But of course it could be the 'headless' main-loop pipe.
Anyhow - hopefully that gives some pointers that you can puzzle through
try to trace / chase down what's going wrong for you.
ATB,
Michael.
--
michael.me...@collabora.com , Pseudo Engineer, itinerant idiot
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Yes, that slowdown occurs with different versions of LO for me as well. Jens On Wed, Jan 07, 2015 at 03:50:21PM +0100, Maarten Hoes wrote: Hi, markus.mohrh...@googlemail.com wrote: Ah. I fear that this is a regression introduced through my code. This sounds a bit like the glxtest codewhich might not work optimally in a headless setup. I suppose you are using 4-4 or master. Regards, Markus I can reproduce the issue with (at least, didnt try any others) LibreOffice 4.2.7.2 (Ubuntu 14.04), LibreOffice 4.3.4.1 (Fedora 21), and master. - Maarten -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hey,
On Wed, Jan 7, 2015 at 10:27 AM, Michael Meeks michael.me...@collabora.com
wrote:
Hi Maarten,
On Wed, 2015-01-07 at 09:21 +0100, Maarten Hoes wrote:
Two more things I noticed, though again Im not sure how relevant those
are, it's probably nothing :
So the thing you're looking for looks often like this:
3986 1420550762.879658 poll([{fd=6, events=POLLIN}], 1, 4294967295
unfinished ...
3986 1420550767.916824 ... poll resumed ) = 1 ([{fd=6, revents=POLLIN}])
Which is from your log; the poll that timed out just before it is
~irrelevant we tend to do a zero timeout (non-blocking) poll before we
do a blocking one for one reason and another - ignore that.
The question is - what is this fd 6 we are polling on - I searched
backwards in your log for ') = 6$' and got:
3986 1420550762.752026
open(/home/buildslave/source/libo-core/instdir/program/../program/bootstraprc,
O_RDONLY|O_EXCL unfinished ...
3986 1420550762.752085 ... open resumed ) = 6
Which is nonsense - since we immediately close that fd again. So
then I
looked for socket = and pipe:
3986 1420550762.753764 pipe( unfinished ...
3986 1420550762.753808 ... pipe resumed [6, 7]) = 0
Which seems to be in this context:
3986 1420550762.753207
lstat(/home/buildslave/source/libo-core/instdir/program,
{st_mode=S_IFDIR|0775, st_size=20480, ...}) = 0
3986 1420550762.753235
lstat(/home/buildslave/source/libo-core/instdir/program/libvcllo.so,
{st_mode=S_IFREG|0775, st_size=8609416, ...}) = 0
3986 1420550762.753259 futex(0x7f160b8d50c8, FUTEX_WAKE_PRIVATE,
2147483647 unfinished ...
3986 1420550762.753285 ... futex resumed ) = 0
3986 1420550762.753764 pipe( unfinished ...
3986 1420550762.753808 ... pipe resumed [6, 7]) = 0
3986 1420550762.753829 fcntl(6, F_GETFD) = 0
3986 1420550762.753867 fcntl(6, F_SETFD, FD_CLOEXEC) = 0
3986 1420550762.753885 fcntl(7, F_GETFD unfinished ...
3986 1420550762.753930 ... fcntl resumed ) = 0
3986 1420550762.753945 fcntl(7, F_SETFD, FD_CLOEXEC) = 0
3986 1420550762.753978 fcntl(6, F_GETFL) = 0 (flags O_RDONLY)
3986 1420550762.754003 fcntl(6, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
3986 1420550762.754028 fcntl(7, F_GETFL) = 0x1 (flags O_WRONLY)
3986 1420550762.754038 fcntl(7, F_SETFL, O_WRONLY|O_NONBLOCK unfinished
...
Which looks like a reasonably normal pipe setup - but - I wonder
what
it's for =) I imagine to communicate with:
3986 1420550762.809356 clone(child_stack=0x7f15f2372eb0,
flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID,
parent_tidptr=0x7f15f23739d0, tls=0x7f15f2373700,
child_tidptr=0x7f15f23739d0) = 3989
Whatever is 'execve'd from that fork - unfortunately I don't see
the -f
strace output there - to be able to follow that. Something (prolly vcl)
spawns something - and we block for 5 seconds on the output of that.
But of course it could be the 'headless' main-loop pipe.
Anyhow - hopefully that gives some pointers that you can puzzle
through
try to trace / chase down what's going wrong for you.
ATB,
Ah. I fear that this is a regression introduced through my code. This
sounds a bit like the glxtest codewhich might not work optimally in a
headless setup. I suppose you are using 4-4 or master.
Regards,
Markus
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, On Mon, Jan 5, 2015 at 10:47 PM, Michael Stahl mst...@redhat.com wrote: On 05.01.2015 18:36, Maarten Hoes wrote: For what its worth, i can easily reproduce the script takes fairly long (about ~50 seconds on my vm's) to complete on both Ubuntu 14.04 and Fedora 21, both with the distro supplied binaries and a recent master. I ran the script using strace -f. It shows a lot of calls on futex( 'FUTEX_WAIT_PRIVATE'), though im not sure how relevant that may be. I attached the strace output. please try that again and use strace options -T -r so it's easier to see where the time is spent. Done. Unfortunately, the resulting file (even compressed) is too large as an attachment for this mailing list. Instead, I uploaded it here : http://filebin.ca/1nCIQSm4AW6n/strace-f-T-r.log.txt.gz Please tell me if that proves to be problematic; im open for other suggestions. this problem is probably not CPU bound, This is correct. My hosts CPU is barely doing anything during the run of the script - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, Im not sure. When I change the accept to include 'tcpNoDelay=1' as below: p = subprocess.Popen(/home/buildslave/source/libo-core/instdir/program/soffice --accept=\socket,host=localhost,port=2002,tcpNoDelay=1;urp;StarOffice.ServiceManager\ --headless, shell=True, env=myenv) I get no noticeable difference. - Maarten. On Tue, Jan 6, 2015 at 12:01 PM, Noel Grandin n...@peralex.com wrote: Just a guess, but I would suspect that setting the TCP_NODELAY socket option on both ends of the socket would speed things up considerably. I think that some BSD-based operating systems have a loopback shortcut in their networking code, which would explain some of the speed difference between Linux and OSX. Disclaimer: http://www.peralex.com/disclaimer.html ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On Tue, 2015-01-06 at 12:31 +0100, Maarten Hoes wrote: Im not sure. When I change the accept to include 'tcpNoDelay=1' as below: In the past - the Linux desktop as a whole suffered something rather similar when code tried to do a reverse lookup on the hostname which took significant time - 20s to timeout each time. IIRC we used to do this inside the is our profile already in-use by another libreoffice process code - which killed us perf-wise long ago. IIRC we binned that idea and updated the mechanism for that. As Tor suggested doing an strace on each end would show what's up: strace -f -ttt -s 256 -o /tmp/slog slow_proces And poke in the /tmp/slog for where there is a multi-second jump in the time - and paste a dozen lines or so around that in each direction =) HTH, Michael. -- michael.me...@collabora.com , Pseudo Engineer, itinerant idiot ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, On Tue, Jan 6, 2015 at 1:28 PM, Michael Meeks michael.me...@collabora.com wrote: As Tor suggested doing an strace on each end would show what's up: strace -f -ttt -s 256 -o /tmp/slog slow_proces And poke in the /tmp/slog for where there is a multi-second jump in the time - and paste a dozen lines or so around that in each direction =) Well I tried this, and it produced a file of a whopping 383087 lines and 30 MB. I wouldnt expect any sane person to look through all of that in its entirety on a page by page basis. ;) I guess that means I cant figure out what's going on. Which leaves me with one last question: Are the large amounts of 'futex(FUTEX_WAIT_PRIVATE) / futex(FUTEX_WAKE_PRIVATE)' expected behavior in this case ? I dont know enough about it to make the call, but it seems to me that inefficient locking may lead to performance issues. Also, futex() is as far as I can tell, a penguin-ism and not available on Mac which may account for the difference ? Just my 2$, please feel free to correct my incorrect assumptions. ;) Anyway, thanks for all the help. - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On Tue, 2015-01-06 at 15:20 +0100, Maarten Hoes wrote: Well I tried this, and it produced a file of a whopping 383087 lines and 30 MB. That is expected. I wouldnt expect any sane person to look through all of that in its entirety on a page by page basis. ;) Hit page-down in 'less' - and when you see the time-stamp 'jump' (ie. we missed 20 seconds ;-) on the left - then that's the interesting bit. Are the large amounts of 'futex(FUTEX_WAIT_PRIVATE) / futex(FUTEX_WAKE_PRIVATE)' expected behavior in this case ? Yes - quite expected - and yes we take locks and release them just for fun all over the place: then again, we shouldn't take contended locks a lot so should avoid the syscall there mostly which is in itself odd - but I doubt that that is related to your problem. ATB, Michael. -- michael.me...@collabora.com , Pseudo Engineer, itinerant idiot ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Just a guess, but I would suspect that setting the TCP_NODELAY socket option on both ends of the socket would speed things up considerably. I think that some BSD-based operating systems have a loopback shortcut in their networking code, which would explain some of the speed difference between Linux and OSX. Disclaimer: http://www.peralex.com/disclaimer.html ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On 05.01.2015 18:36, Maarten Hoes wrote: For what its worth, i can easily reproduce the script takes fairly long (about ~50 seconds on my vm's) to complete on both Ubuntu 14.04 and Fedora 21, both with the distro supplied binaries and a recent master. I ran the script using strace -f. It shows a lot of calls on futex( 'FUTEX_WAIT_PRIVATE'), though im not sure how relevant that may be. I attached the strace output. please try that again and use strace options -T -r so it's easier to see where the time is spent. On Tue, Dec 30, 2014 at 01:58:00PM +0100, Markus Mohrhard wrote: Hey, You or we can now speculate for a long time or you can just start profiling what is actually slow. Get a symbols build and run it with callgrind. You can interpret the results with kcachegrind which will hopefully show what took so much time and allow you to work on a fix. this problem is probably not CPU bound, i'd guess something is waiting for a time-out and callgrind's cycle-counting won't help much in that case. ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Thank you, Maarten. I tried to upload the callgrind data, but the email was rejected due to its size. Glad you can reproduce the slowness! Now the question is: what's to cause of the socket slowness, compared to the pipe performance? Based on yesterday's findings, this might not be a LO issue afterall. Connecting to LO through a pipe gives me the same performance (and faster) that I have on my Mac. It's the socket connect which is so slow. See here for more data: https://forum.openoffice.org/en/forum/viewtopic.php?f=20t=74332p=336914#p336975 The question lingers: why is socket connect on Linux so tremendously slower than on the Mac... http://superuser.com/questions/860321/linux-localhost-sockets-painfully-slower-than-on-mac Jens On Mon, Jan 05, 2015 at 06:36:47PM +0100, Maarten Hoes wrote: Hi, For what its worth, i can easily reproduce the script takes fairly long (about ~50 seconds on my vm's) to complete on both Ubuntu 14.04 and Fedora 21, both with the distro supplied binaries and a recent master. I ran the script using strace -f. It shows a lot of calls on futex( 'FUTEX_WAIT_PRIVATE'), though im not sure how relevant that may be. I attached the strace output. - Maarten -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hey, On Sat, Jan 3, 2015 at 12:09 PM, Maarten Hoes hoes.maar...@gmail.com wrote: On Sat, Jan 3, 2015 at 12:37 AM, Jens Tröger jens.troe...@light-speed.de wrote: Thank you, Maarten, I've run office like so from within the Python script: p = subprocess.Popen(valgrind --tool=callgrind soffice --accept=\socket,host=localhost,port=2002;urp;StarOffice.ServiceManager\, shell=True, env=myenv) and got five callgrind.out.* files once the script terminated soffice. I ran those through callgrind_annotate callgrind.out.* Note that I'm using the default office image which (I assume) has no debug symbols. The data doesn't make much sense. Considering the loop in question ran for about ~45sec (with and without valgrind?!) then I'd expect an instruction count _much_ larger than a few hundreds of thousands. In all four profiles, though, libc's _dl_addr and ld's symbol lookup take most of the time. Not sure I trust these profiles. Attached. Jens Yes, it looks like you are using the libreoffice rpm/deb package that was installed on your linux distribution in '/usr/bin/soffice'. I dont think that that one will have debugging symbols (at least, not by default. Fedora allows you to install 'libreoffice-debuginfo', not sure about Ubuntu). Im not sure if this will change anything, but could you use the build that sits in the sourcetree in 'instdir/program/soffice' when the build finishes ? Specify it with the full absolute path, like for example : /home/buildslave/source/libo-core/instdir/program/soffice It appears that the default way to build libreoffice, if you dont explicitly specify otherwise, is to include the debug symbols (my build has them). Nearly all distros provide debuginfos that will make the callgrind output somewhat nicer. In a self build tree you need to use --enable-symbols as option (no enable-debug or enable-dbgutil as they will remove the optimization that is necessary for useful profiling). To analyze the callgrind output you should use kcachegrind which provides a nice UI to go through the results. Regards, Markus ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On Sat, Jan 3, 2015 at 12:37 AM, Jens Tröger jens.troe...@light-speed.de wrote: Thank you, Maarten, I've run office like so from within the Python script: p = subprocess.Popen(valgrind --tool=callgrind soffice --accept=\socket,host=localhost,port=2002;urp;StarOffice.ServiceManager\, shell=True, env=myenv) and got five callgrind.out.* files once the script terminated soffice. I ran those through callgrind_annotate callgrind.out.* Note that I'm using the default office image which (I assume) has no debug symbols. The data doesn't make much sense. Considering the loop in question ran for about ~45sec (with and without valgrind?!) then I'd expect an instruction count _much_ larger than a few hundreds of thousands. In all four profiles, though, libc's _dl_addr and ld's symbol lookup take most of the time. Not sure I trust these profiles. Attached. Jens Yes, it looks like you are using the libreoffice rpm/deb package that was installed on your linux distribution in '/usr/bin/soffice'. I dont think that that one will have debugging symbols (at least, not by default. Fedora allows you to install 'libreoffice-debuginfo', not sure about Ubuntu). Im not sure if this will change anything, but could you use the build that sits in the sourcetree in 'instdir/program/soffice' when the build finishes ? Specify it with the full absolute path, like for example : /home/buildslave/source/libo-core/instdir/program/soffice It appears that the default way to build libreoffice, if you dont explicitly specify otherwise, is to include the debug symbols (my build has them). - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, On Sat, Jan 03, 2015 at 12:51:02PM +0100, Maarten Hoes wrote: markus.mohrh...@googlemail.com wrote: Nearly all distros provide debuginfos that will make the callgrind output somewhat nicer. In a self build tree you need to use --enable-symbols as option (no enable-debug or enable-dbgutil as they will remove the optimization that is necessary for useful profiling). Thanks. I wasnt sure about Ubuntu. But it looks like Ubuntu has the 'debuginfo-install' command to install debug symbols for a given package. - Maarten On Ubuntu I had to sudo apt-get install libreoffice-dbg which pulled in the debug information. It also installed a few more packages that provide debug info for libraries. I actually made the mistake to valgrind soffice which is a bash script, instead of /usr/lib/libreoffice/program/soffice.bin which is the actual executable. Running soffice.bin under callgrind took _way_ longer which makes sense, considering the added overhead of the instrumentation. The results of that run are attached. Furthermore, instead of profiling the LO binary I also profiles the Python run itself. What troubles me with the current scenario is that running LO inside of an IPy Notebook seems to have run for the expected 2 sec, see this answer to my thread: https://forum.openoffice.org/en/forum/viewtopic.php?f=20t=74332p=336914#p336350 Does the call profile for LO raise a flag to any of you devs? Cheers, Jens -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
I wonder if the poor perf got to do with UNO and Python. On my Mac, LO ships with its own Python interpreter instead of just providing the UNO hooks like it does on Linux. 32b LibreOffice on Mac (py 3.3.5) Elapsed time: 1.8361830711364746 with 550 pars 64b LibreOffice on Mac (py 3.3.5) Elapsed time: 0.8173670768737793 with 550 pars 64b LibreOffice on Linux (py 3.4.2) -- Gentoo, Ubuntu, Mint Elapsed time: 45.529000759124756 with 550 pars In every instance, the binaries are provided, I don't build any of them. What is different, however, is the runtime environment? Would that make sense? Jens -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, On Sat, Jan 3, 2015 at 12:28 PM, Markus Mohrhard markus.mohrh...@googlemail.com wrote: Nearly all distros provide debuginfos that will make the callgrind output somewhat nicer. In a self build tree you need to use --enable-symbols as option (no enable-debug or enable-dbgutil as they will remove the optimization that is necessary for useful profiling). Thanks. I wasnt sure about Ubuntu. But it looks like Ubuntu has the 'debuginfo-install' command to install debug symbols for a given package. - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On Sat, Jan 3, 2015 at 5:22 PM, Jens Tröger jens.troe...@light-speed.de
wrote:
I wonder if the poor perf got to do with UNO and Python. On my Mac, LO
ships
with its own Python interpreter instead of just providing the UNO hooks
like it does on Linux.
32b LibreOffice on Mac (py 3.3.5)
Elapsed time: 1.8361830711364746 with 550 pars
64b LibreOffice on Mac (py 3.3.5)
Elapsed time: 0.8173670768737793 with 550 pars
64b LibreOffice on Linux (py 3.4.2) -- Gentoo, Ubuntu, Mint
Elapsed time: 45.529000759124756 with 550 pars
In every instance, the binaries are provided, I don't build any of them.
What is different, however, is the runtime environment? Would that make
sense?
I guess one could test that hypothesis by building libreoffice from sources
for oneself, and specifying '--enable-python=internal' to autogen.sh in
order to build the python that comes with the libreoffice sources, and use
that one ('instdir/program/python') instead of the system provided version ?
- Maarten
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Oh, misunderstanding :) The attached files are already digested with callgrind_annotate, you can just open in vim. Jens On Sat, Jan 03, 2015 at 08:08:23PM +0100, Maarten Hoes wrote: Hi, Perhaps its just me, but when I try to open up the traces you send, I get the following error message : Could not open the file 'callgrind.out.3708-annotate' Check that it exists and you have enough permissions to read it. I verified I have the proper permissions, so that is not the answer, and the message produced here is misleading. However, I can reproduce the behavior by trying to load any tracefile at all that has been annotated with 'callgrind_annotate'. Loading tracefiles that have not been modified load fine on my system. Could you please mail the original (not annotated) files that 'valgrind --tool=callgrind' produced to the list ? - Maarten -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, Perhaps its just me, but when I try to open up the traces you send, I get the following error message : Could not open the file 'callgrind.out.3708-annotate' Check that it exists and you have enough permissions to read it. I verified I have the proper permissions, so that is not the answer, and the message produced here is misleading. However, I can reproduce the behavior by trying to load any tracefile at all that has been annotated with 'callgrind_annotate'. Loading tracefiles that have not been modified load fine on my system. Could you please mail the original (not annotated) files that 'valgrind --tool=callgrind' produced to the list ? - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
The following is interesting: On Sat, Jan 03, 2015 at 05:22:42PM +0100, Jens Tröger wrote: 32b LibreOffice on Mac (py 3.3.5) Elapsed time: 1.8361830711364746 with 550 pars 64b LibreOffice on Mac (py 3.3.5) Elapsed time: 0.8173670768737793 with 550 pars 64b LibreOffice on Linux (py 3.4.2) -- Gentoo, Ubuntu, Mint Elapsed time: 45.529000759124756 with 550 pars Pipe mode versus socket mode. When I spawn LO to listen to a named pipe instead of a localhost:2002 socket, then performance is dramatically different on Linux: On the remote Gentoo Linux server Pipe mode: Elapsed time: 0.5140466690063477 with 550 pars Socket mode: Elapsed time: 45.658066272735596 with 550 pars On the local Ubuntu Linux machine Pipe mode: Elapsed time: 0.8761096000671387 with 550 pars Socket mode: Elapsed time: 45.715266942977905 with 550 pars On my Mac Pipe mode: Elapsed time: 1.941413164138794 with 550 pars Socket mode: Elapsed time: 1.941413164138794 with 550 pars This doesn't quite solve the problem of why using sockets on Linux is so much slower, but it does solve the larger problem of having an efficient connection from an UNO Py client to the office server. Jens -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Thank you, Maarten, I've run office like so from within the Python script: p = subprocess.Popen(valgrind --tool=callgrind soffice --accept=\socket,host=localhost,port=2002;urp;StarOffice.ServiceManager\, shell=True, env=myenv) and got five callgrind.out.* files once the script terminated soffice. I ran those through callgrind_annotate callgrind.out.* Note that I'm using the default office image which (I assume) has no debug symbols. The data doesn't make much sense. Considering the loop in question ran for about ~45sec (with and without valgrind?!) then I'd expect an instruction count _much_ larger than a few hundreds of thousands. In all four profiles, though, libc's _dl_addr and ld's symbol lookup take most of the time. Not sure I trust these profiles. Attached. Jens On Wed, Dec 31, 2014 at 09:09:19AM +0100, Maarten Hoes wrote: Hrm. Perhaps a wiki page may not be needed after all; it doesnt seem to get more complicated than this ? : valgrind --tool=callgrind instdir/program/soffice And then load the contents of callgrind.out.pid in KCachegrind ? - Maarten -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On Tue, Dec 30, 2014 at 4:44 PM, Maarten Hoes hoes.maar...@gmail.com wrote: On Tue, Dec 30, 2014 at 4:24 PM, Jens Tröger jens.troe...@light-speed.de wrote: hopefully function call profiling yields more... Which makes the following question pop up in my mind: does the wiki already have a page describing how to set up function call profiling with libreoffice ? (i couldnt find any). Is there a strong preference for a tool to use ? (gprof vs. vallgrind/callgrind vs.). I could take a sec. to write up a (tested) page with the procedure if people can describe the basic preferred way to do it on list. ;) Hrm. Perhaps a wiki page may not be needed after all; it doesnt seem to get more complicated than this ? : valgrind --tool=callgrind instdir/program/soffice And then load the contents of callgrind.out.pid in KCachegrind ? - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Connection is not the problem, I have already connected and that took far less than a second on localhost. The code in question is this: start_time = time.time() parenum = document.Text.createEnumeration() while parenum.hasMoreElements() : par = parenum.nextElement() end_time = time.time() print(Elapsed time: + str(end_time - start_time)) Unless office attempts to connect somewhere (where to, anyway?) the reason for the performance drop is elsewhere. The above loop runs 1s on my Mac, and 45s on Linux. Other test documents show performance difference of 3s (Mac) vs 3.45min (Linux). If office would attempt (and time-out) to connect while iterating over the paragraphs, the runtime would be _much_ worse. Jens On Tue, Dec 30, 2014 at 08:34:03AM +0200, Noel Grandin wrote: when connecting to something on the local machine, if the machine name or the localhosts entry is /etc/hosts is incorrectly setup, the connection process can take an extra 30 seconds while the socket library performs a DNS lookup that times out. -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hey, On Tue, Dec 30, 2014 at 1:50 PM, Jens Tröger jens.troe...@light-speed.de wrote: Connection is not the problem, I have already connected and that took far less than a second on localhost. The code in question is this: start_time = time.time() parenum = document.Text.createEnumeration() while parenum.hasMoreElements() : par = parenum.nextElement() end_time = time.time() print(Elapsed time: + str(end_time - start_time)) Unless office attempts to connect somewhere (where to, anyway?) the reason for the performance drop is elsewhere. The above loop runs 1s on my Mac, and 45s on Linux. Other test documents show performance difference of 3s (Mac) vs 3.45min (Linux). If office would attempt (and time-out) to connect while iterating over the paragraphs, the runtime would be _much_ worse. Jens You or we can now speculate for a long time or you can just start profiling what is actually slow. Get a symbols build and run it with callgrind. You can interpret the results with kcachegrind which will hopefully show what took so much time and allow you to work on a fix. Regards, Markus ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
You or we can now speculate for a long time or you can just start profiling what is actually slow. Get a symbols build and run it with callgrind. Or even just run it under strace for a start, doesn't even require re-building it. --tml ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
I'd love to, however, I can't even build the thing. See my other thread on autogen.sh failing. Also, I figure that somebody who works on LO might know what's going on, and I hoped that I don't have to spend days trying to dig around something that might be obvious to the devs. Are there prebuild drops that contain dbg and prof information already which I can work with? Jens On Tue, Dec 30, 2014 at 01:58:00PM +0100, Markus Mohrhard wrote: Hey, You or we can now speculate for a long time or you can just start profiling what is actually slow. Get a symbols build and run it with callgrind. You can interpret the results with kcachegrind which will hopefully show what took so much time and allow you to work on a fix. Regards, Markus -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hi, On Tue, Dec 30, 2014 at 2:14 PM, Jens Tröger jens.troe...@light-speed.de wrote: Are there prebuild drops that contain dbg and prof information already which I can work with? Im not sure if the daily builds you can find here have debug symbols included (for example, 'Linux-rpm_deb-x86_64@46-TDF-dbg' sounds promising ?) but you could nose around ?: http://dev-builds.libreoffice.org/daily/master/ But perhaps your Linux distribution has packages for use with the libreoffice that comes with your distro, like libreoffice-debuginfo ? http://rpm.pbone.net/index.php3?stat=3search=libreoffice-debuginfosrodzaj=3 Or like already mentioned, you could start with running it under strace and see if that already turns up something useful ? http://linux.die.net/man/1/strace Regards, Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Thanks Maarten, I'll take a look at the links, and I'll check if Ubuntu provides dbg information. Strace didn't log anything calls other than wait for the loop iteration; hopefully function call profiling yields more... Jens On Tue, Dec 30, 2014 at 04:06:04PM +0100, Maarten Hoes wrote: Hi, Im not sure if the daily builds you can find here have debug symbols included (for example, 'Linux-rpm_deb-x86_64@46-TDF-dbg' sounds promising ?) but you could nose around ?: http://dev-builds.libreoffice.org/daily/master/ But perhaps your Linux distribution has packages for use with the libreoffice that comes with your distro, like libreoffice-debuginfo ? http://rpm.pbone.net/index.php3?stat=3search=libreoffice-debuginfosrodzaj=3 Or like already mentioned, you could start with running it under strace and see if that already turns up something useful ? http://linux.die.net/man/1/strace Regards, Maarten -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
On Tue, Dec 30, 2014 at 4:24 PM, Jens Tröger jens.troe...@light-speed.de wrote: hopefully function call profiling yields more... Which makes the following question pop up in my mind: does the wiki already have a page describing how to set up function call profiling with libreoffice ? (i couldnt find any). Is there a strong preference for a tool to use ? (gprof vs. vallgrind/callgrind vs.). I could take a sec. to write up a (tested) page with the procedure if people can describe the basic preferred way to do it on list. ;) - Maarten ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
I have no preference tools-wise. On Tue, Dec 30, 2014 at 04:44:42PM +0100, Maarten Hoes wrote: Which makes the following question pop up in my mind: does the wiki already have a page describing how to set up function call profiling with libreoffice ? (i couldnt find any). Is there a strong preference for a tool to use ? (gprof vs. vallgrind/callgrind vs.). I could take a sec. to write up a (tested) page with the procedure if people can describe the basic preferred way to do it on list. ;) - Maarten -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 On 30/12/14 12:50, Jens Tröger wrote: Unless office attempts to connect somewhere (where to, anyway?) Where are you getting the builds from? On at least one distro, the version in their repository calls home. jonathon -BEGIN PGP SIGNATURE- Version: GnuPG v1 iQIcBAEBAgAGBQJUo6jtAAoJEE1PKy9+kxplLsQP/jeEA9sERiqQOZWURK5nNdSj pZYDsiwzUPYlkeoiC1mCZCe5fDFn4UnrZKFJMc2Zh30riw+ejBNXOsB4jK8UL4pH /B9sEWhvqCoiCTLUFV7R37h4/9khdKJqQfUt8etvqfefyJ9FJr7PmXsVQJjtIjBl Jg+fLfPMnSa1Vvum0C16o5sU4L83RpA056RbZpjYkucgAp0A/Qvdmhm3g3FDaqS5 j9IkHPfpoombRaAIptU969CwH3OazVblUJ1kr+V3Y6l0r/0YnbBXoxqE7cMQMkRX F7qQuWG2A2eYKcdSortl2kTFxrAuirbth27KOhikrHgpqFXC7GDX43swvbwoPuRA Tcimp5Qou2MrYPbRSPE5znYaAlhy5nJV2nREqemhF/vMyuapvMlr247sMWAkD7nh hhe30gIcDkZCO3DVG521PHyeAvyxeCUcGcc4oDIkWb0GaRUbblHR9m/t3v2uvbNx l87/1xF9iK53sVLi2twOx/f6wnWgJv8jYFzpycV2iz0TCaamS6e+E2DQwNAMC2iX zTs8eyEAvZQJh3VpgsgimIma2VVzs2Q3Kibba1dCMZ8b7j3C0Cb1NwXLbbPmbRfb L1yO+zN/GEYDTVQa0adnmP3dx+FzVXpIidK8T6OpVdlCG9vzigo+p3M0P9N089kG fyr+wvGKq7OHc1h88cZ3 =+fbT -END PGP SIGNATURE- ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
That smells like a DNS timeout. I suspect that you have some kind of network problem. ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Could you elaborate, please? On Mon, Dec 29, 2014 at 01:44:51PM +0200, Noel Grandin wrote: That smells like a DNS timeout. I suspect that you have some kind of network problem. -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
Hello, Il 29/12/2014 12:02, Jens Tröger ha scritto: Hello, I'm opening this ML thread based on the following two forum discussions, none of which have yielded much resolution yet: http://en.libreofficeforum.org/node/9850 https://forum.openoffice.org/en/forum/viewtopic.php?f=20t=74332 To summarize: I run an office instance locally, headless, as a listener. Using Python and UNO I connect to that office instance, load a test document, and iterate over its paragraphs. On my Mac this takes 1.5s while on Linux it takes about 45s, a severe degradation in performance. I could reproduce this across three different Linux machines now consistently (Gentoo, Ubuntu). Reproduced here too with 4.4.0 beta1 I have not yet started a more thorough profiling of the office instance, hoping that raising this issue to the developers might solve the problems. Well you can fire a profiler, but also you can add a few more prints to see it the slowness is in the loop or from .createEnumeration(). thanks, riccardo ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
That would mean that with every access through the UNO bridge and advance of the paragraph iterator, office would make some network access? Why? On Mon, Dec 29, 2014 at 01:44:51PM +0200, Noel Grandin wrote: That smells like a DNS timeout. I suspect that you have some kind of network problem. -- Jens Tröger http://savage.light-speed.de/ ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
Re: Severe performance degradation on Linux
when connecting to something on the local machine, if the machine name or the localhosts entry is /etc/hosts is incorrectly setup, the connection process can take an extra 30 seconds while the socket library performs a DNS lookup that times out. ___ LibreOffice mailing list LibreOffice@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/libreoffice
