Performance/Startup

From Apache OpenOffice Wiki
< Performance
Revision as of 11:48, 30 April 2009 by Sb (Talk | contribs)

Jump to: navigation, search

Performance 170.png
Performance Project

performance.openoffice.org

Quick Navigation

Team

Communication

Activities

About this template


Issues

  • CWS sb103, integrated in OOO310_m1 and DEV300_m42:
  • CWS sb107, targeting OOo 3.2:
    • Issue 85679 “Link with -Wl,-Bsymbolic-functions -Wl,--dynamic-list-cpp-new -Wl,--dynamic-list-cpp-typeinfo when supported”
    • Issue 99519 “Remove unnecessary library dependencies” (“[t]his cleanup has no positive impact on OOo startup performance though”—[1])
    • Issue 100348 “svt, bf_svt export symbols from jpeg archive”
    • Issue 100396 “svtools: costly external data symbols sHTML_xxx/sRTF_xxx”
    • Issue 100576 “enable HAVE_LD_HASH_STYLE in sdev300.ini”
  • analyzing startup to identify performance problems (ongoing)

Details

Additional processes during startup

Starting OOo DEV300m39 unxlngi6.pro on v20z-so3 (some old Ubuntu machine), soffice.bin spawns additional processes during start up:

$ strace -fF opt/openoffice.org3/program/soffice.bin 2>&1 | grep 'exec.*('
execve("ooo/opt/openoffice.org3/program/soffice.bin", ["ooo/opt/openoffice.org3/program/"...], [/* 17 vars */]) = 0
[pid 19800] execve("/usr/lib/libgconf2-4/gconfd-2", ["/usr/lib/libgconf2-4/gconfd-2", "17"], [/* 18 vars */] <unfinished ...>
[pid 19802] execve("/bin/sh", ["sh", "-c", "sh -c paperconf 2>/dev/null"], [/* 18 vars */]) = 0
[pid 19803] execve("/bin/sh", ["sh", "-c", "paperconf"], [/* 17 vars */]) = 0

It turns out only the first additional process (/usr/lib/libgconf2-4/gconfd-2) is spawned directly from soffice.bin (and the following ones are in turn spawned from that process), and it is spawned during a call to gconf_client_preload:

$ gdb opt/openoffice.org3/program/soffice.bin
(gdb) break fork
Breakpoint 2 at 0xb7c6f584
(gdb) run
Breakpoint 2, 0xb7c6f584 in fork () from /lib/tls/i686/cmov/libpthread.so.0
(gdb) info threads
  4 Thread -1296356432 (LWP 19893)  0xffffe410 in __kernel_vsyscall ()
  3 Thread -1287963728 (LWP 19892)  0xffffe410 in __kernel_vsyscall ()
  2 Thread -1251386448 (LWP 19889)  0xffffe410 in __kernel_vsyscall ()
* 1 Thread -1251252000 (LWP 19887)  0xb7c6f584 in fork ()
   from /lib/tls/i686/cmov/libpthread.so.0
(gdb) where
#0  0xb7c6f584 in fork () from /lib/tls/i686/cmov/libpthread.so.0
#1  0xb496593a in g_spawn_error_quark () from /usr/lib/libglib-2.0.so.0
#2  0xb49660fe in g_spawn_async_with_pipes () from /usr/lib/libglib-2.0.so.0
#3  0xb496617b in g_spawn_async () from /usr/lib/libglib-2.0.so.0
#4  0xb34a4ec6 in gconf_activate_server () from /usr/lib/libgconf-2.so.4
#5  0xb34afc29 in gconf_debug_shutdown () from /usr/lib/libgconf-2.so.4
#6  0xb34b06e1 in gconf_spawn_daemon () from /usr/lib/libgconf-2.so.4
#7  0xb34b091a in gconf_spawn_daemon () from /usr/lib/libgconf-2.so.4
#8  0xb34b148c in gconf_engine_all_entries () from /usr/lib/libgconf-2.so.4
#9  0xb34b7540 in gconf_client_all_entries () from /usr/lib/libgconf-2.so.4
#10 0xb34e0f9c in GconfLayer::getTimestamp (this=0xb342dc1c)
    at /so/ws/DEV300/ooo/shell/source/backends/gconfbe/gconflayer.cxx:528
#11 0xb35dc4c3 in configmgr::backend::BinaryReadHandler::validateHeader (
    this=0xbffcf42c, pLayers=0xb33c2020, nNumLayers=6,
    _aSchemaVersion=@0xbffcf550, aRequestedLocale=@0xbffcf530,
    outKnownLocales=@0xbffcf540) at Reference.h:366
#12 0xb35dd151 in configmgr::backend::BinaryCache::readComponentData (
    this=0xb33bca1c, aComponentData=@0xbffcf698, aFactory=@0xbffcf510,
    aComponent=@0xbffcf6c8, aSchemaVersion=@0xbffcf550, aEntity=@0xbffcf520,
    aRequestedLocale=@0xbffcf530, outKnownLocales=@0xbffcf540,
    pLayers=0xb33c2020, nNumLayers=6, bIncludeTemplates=true)
    at /so/ws/DEV300/ooo/configmgr/source/backend/binarycache.cxx:200
#13 0xb35cc7bd in configmgr::backend::BackendAccess::readDefaultData (
    this=0xb4584d5c, aComponentData=@0xbffcf698, aComponent=@0xbffcf6c8,
    aOptions=@0xbffcf83c, bIncludeTemplates=true, pLayers=0xb33c2020,
    nNumLayers=6, aTemplateProvider=0xb352d60c, pLayersMerged=0xbffcf644)
    at /so/ws/DEV300/ooo/configmgr/source/backend/backendaccess.cxx:84
#14 0xb35cd9bd in configmgr::backend::BackendAccess::getNodeData (
    this=0xb4584d5c, aRequest=@0xbffcf838, _aTemplateProvider=0xb352d60c,
    aListener=0xb352d610) at request.hxx:75
#15 0xb35934e5 in configmgr::backend::CacheController::loadDirectly (
    this=0xb352d604, _aRequest=@0xbffcf838, _bAddListenter=true) at ref.hxx:167
#16 0xb3597198 in configmgr::backend::CacheController::loadComponent (
    this=0xb352d604, _aRequest=@0xbffcf838)
    at /so/ws/DEV300/ooo/configmgr/source/treecache/cachecontroller.cxx:376
#17 0xb359b6d4 in configmgr::TreeManager::requestSubtree (this=0xb4584eac,
    aSubtreePath=@0xbffcf960, _aOptions=@0xbffcf83c) at ref.hxx:99
#18 0xb36517e9 in configmgr::OProviderImpl::requestSubtree (this=0xb458b31c,
    aSubtreePath=@0xbffcf960, _aOptions=@0xbffcf9a0) at ref.hxx:167
#19 0xb3652f6b in configmgr::OProviderImpl::buildReadAccess (this=0xb458b31c,
    _rAccessor=@0xbffcf9c0, _aOptions=@0xbffcf9a0, nMinLevels=-1)
    at /so/ws/DEV300/ooo/configmgr/source/api2/providerimpl.cxx:490
#20 0xb36532b5 in configmgr::OProviderImpl::createReadAccess (this=0xb458b31c,
    aArgs=@0xbffcfb80)
    at /so/ws/DEV300/ooo/configmgr/source/api2/providerimpl.cxx:860
#21 0xb364b799 in configmgr::OProvider::createInstanceWithArguments (
    this=0xb376a554, aServiceSpecifier=@0xbffcfb20, aArguments=@0xbffcfb80)
    at Reference.h:359
#22 0xb690b180 in DefaultFontConfiguration (this=0xb33c3394) at Reference.h:366
#23 0xb690ba5f in vcl::DefaultFontConfiguration::get ()
    at /so/ws/DEV300/ooo/vcl/source/gdi/fontcfg.cxx:107
#24 0xb684818d in ImplStyleData::SetStandardStyles (this=0xb33df618)
    at ustring.hxx:111
#25 0xb6848945 in ImplStyleData (this=0xb33df618)
    at /so/ws/DEV300/ooo/vcl/source/app/settings.cxx:438
#26 0xb6848eef in StyleSettings (this=0x0)
    at /so/ws/DEV300/ooo/vcl/source/app/settings.cxx:640
#27 0xb684aa98 in ImplAllSettingsData (this=0xb33b71c8)
    at /so/ws/DEV300/ooo/vcl/source/app/settings.cxx:1523
#28 0xb684b244 in AllSettings (this=0x0)
    at /so/ws/DEV300/ooo/vcl/source/app/settings.cxx:1590
#29 0xb684ce12 in Application::GetSettings ()
    at /so/ws/DEV300/ooo/vcl/source/app/svapp.cxx:814
#30 0xb68c699c in OutputDevice (this=0xb458e924)
    at /so/ws/DEV300/ooo/vcl/source/gdi/outdev.cxx:427
#31 0xb6a18618 in Window (this=0xb458e924, nType=383)
    at /so/ws/DEV300/ooo/vcl/source/window/window.cxx:4288
#32 0xb69ee0b7 in SystemWindow (this=0xb458e924, nType=0)
    at /so/ws/DEV300/ooo/vcl/source/window/syswin.cxx:83
#33 0xb6a28a72 in WorkWindow (this=0xb458e924, nType=0)
    at /so/ws/DEV300/ooo/vcl/source/window/wrkwin.cxx:114
#34 0xb69c8151 in IntroWindow (this=0xb458e924)
    at /so/ws/DEV300/ooo/vcl/source/window/introwin.cxx:61
#35 0xb239185d in SplashScreen (this=0xb458e908, rSMgr=@0x0)
    at /so/ws/DEV300/ooo/desktop/source/splash/splash.cxx:83
#36 0xb2391b10 in desktop::SplashScreen::getInstance (rSMgr=@0xbffcfdec)
    at weak.hxx:91
#37 0xb77d9206 in cppu::OSingleFactoryHelper::createInstanceEveryTime (
    this=0xb33b726c, xContext=@0x1) at Reference.h:359
#38 0xb77d88be in cppu::OSingleFactoryHelper::createInstanceWithContext (
    this=0x0, xContext=@0xb4e41ad8) at Reference.h:359
#39 0xb77d8cb1 in cppu::OFactoryComponentHelper::createInstanceWithContext (
    this=0xb33b7238, xContext=@0xb4e41ad8) at Reference.h:359
#40 0xb77d9988 in cppu::OSingleFactoryHelper::createInstanceWithArgumentsAndContext (this=0x0, rArguments=@0xbffd0160, xContext=@0xb4e41ad8) at Reference.h:359
#41 0xb77da48e in cppu::OFactoryComponentHelper::createInstanceWithArgumentsAndContext (this=0xb33b7238, rArguments=@0xbffd0160, xContext=@0xb4e41ad8)
    at Reference.h:359
#42 0xb77dadce in cppu::ORegistryFactoryHelper::createInstanceWithArgumentsAndContext (this=0xb33b4264, rArguments=@0xbffd0160, xContext=@0xb4e41ad8)
    at Reference.h:366
#43 0xb45f68e9 in stoc_smgr::OServiceManager::createInstanceWithArgumentsAndContext (this=0xb33b42a0, rServiceSpecifier=@0xbffd0130, rArguments=@0xbffd0160,
    xContext=@0xb4e41ad8) at Reference.h:366
#44 0xb45f61a8 in stoc_smgr::OServiceManager::createInstanceWithArguments (
    this=0x1, rServiceSpecifier=@0xbffd0130, rArguments=@0xbffd0160)
    at Reference.h:359
#45 0xb7dbcc21 in desktop::Desktop::OpenSplashScreen (this=0xbffd04a4)
    at Reference.h:121
#46 0xb7dbd296 in desktop::Desktop::Main (this=0xbffd04a4)
    at /so/ws/DEV300/ooo/desktop/source/app/app.cxx:1232
#47 0xb6852372 in ImplSVMain ()
    at /so/ws/DEV300/ooo/vcl/source/app/svmain.cxx:194
#48 0xb68524fd in SVMain () at /so/ws/DEV300/ooo/vcl/source/app/svmain.cxx:235
#49 0xb7de6e23 in soffice_main ()
    at /so/ws/DEV300/ooo/desktop/source/app/sofficemain.cxx:52
#50 0x08048dea in main (argc=1, argv=0xbffd0584) at main.c:38
(gdb) cont
Program exited normally.
(gdb) quit

The first call to gconf_client_preload (that presumably does the spawning) accounts for 0.05 seconds of real time during start up:

$ patch -p 0 <<-\EOF
	Index: tags/DEV300_m39/shell/source/backends/gconfbe/gconflayer.cxx
	===================================================================
	--- tags/DEV300_m39/shell/source/backends/gconfbe/gconflayer.cxx        (revision 266425)
	+++ tags/DEV300_m39/shell/source/backends/gconfbe/gconflayer.cxx        (working copy)
	@@ -1,3 +1,6 @@
	+/*SB*/#include<stdio.h>
	+/*SB*/#include<sys/times.h>
	+/*SB*/#include<unistd.h>
	 /*************************************************************************
	  *
	  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
	@@ -524,8 +527,10 @@
	     GConfValue* aGconfValue;
	     int i = 0;
	
	+/*SB*/tms TMS;clock_t TIME=times(&TMS);
	     while( m_pPreloadValuesList[i] != NULL )
	         gconf_client_preload( aClient, m_pPreloadValuesList[i++], GCONF_CLIENT_PRELOAD_ONELEVEL, NULL );
	+/*SB*/TIME=times(&TMS)-TIME;fprintf(stderr,"time %f\n",double(TIME)/sysconf(_SC_CLK_TCK));for(int N=0;N<i;++N)fprintf(stderr," preload %d <%s>\n",N,m_pPreloadValuesList[N]);
	
	     for( i = 0; i < m_nConfigurationValues; i++ )
	     {
EOF
$ opt/openoffice.org3/program/soffice.bin
time 0.050000
 preload 0 </desktop/gnome/interface>
time 0.010000
 preload 0 </desktop/gnome/url-handlers/mailto>
time 0.000000

The overhead of the soffice wrapper script around soffice.bin is roughly as follows (see issue 97491 “"soffice" now being binary instead of shellscript” for temporary problems with the soffice wrapper script), where javaldx and pagein are among the executables called from the script:

$ rm opt/openoffice.org3/program/soffice.bin
$ ln -s /bin/true opt/openoffice.org3/program/soffice.bin
$ time opt/openoffice.org3/program/soffice
real    0m0.170s
user    0m0.060s
sys     0m0.110s
$ time opt/openoffice.org3/program/../basis-link/ure-link/bin/javaldx "-env:INIFILENAME=vnd.sun.star.pathname:${PWD?}/opt/openoffice.org3/program/redirectrc"
/usr/java/jdk1.6.0_03/jre/lib/i386/client:/usr/java/jdk1.6.0_03/jre/lib/i386/native_threads:/usr/java/jdk1.6.0_03/jre/lib/i386
real    0m0.024s
user    0m0.020s
sys     0m0.000s
$ time opt/openoffice.org3/program/../basis-link/program/pagein "-L${PWD?}/opt/openoffice.org3/program/../basis-link/program" @pagein-common
real    0m0.102s
user    0m0.020s
sys     0m0.080s

ELF Dynamic Objects

At least on ELF based systems, one factor that controls how much of a dynamic library needs to be loaded in initially are the relocations in the .rel.dyn section (the .rel.plt section is not relevant directly at load time unless you force LD_BIND_NOW). The following gives the number of relocations per ELF dynamic object in a DEV300m41 unxlngi6.pro OOo installation (libicudata.so.40.0 has no relocations), for some rough guiding numbers:

$ cd DEV300m41-unxlngi6.pro-en_US && find opt -type f -exec bash -c 'file "$0" | fgrep -q " ELF " && echo $(readelf -r "$0" | grep "^Relocation section .*rel.dyn" | cut -d " " -f 8) "$0"' {} \; | sort -n
opt/openoffice.org/basis3.0/program/libicudata.so.40.0
1 opt/openoffice.org/basis3.0/program/python.bin
2 opt/openoffice.org/basis3.0/program/gnome-open-url.bin
2 opt/openoffice.org/basis3.0/program/pagein
2 opt/openoffice.org/basis3.0/program/uri-encode
3 opt/openoffice.org3/program/crash_report.bin
3 opt/openoffice.org/basis3.0/program/msfontextract
6 opt/openoffice.org/basis3.0/program/pyuno.so
7 opt/openoffice.org/basis3.0/program/libprldap50.so
7 opt/openoffice.org/basis3.0/program/libtextcat.so
8 opt/openoffice.org3/program/soffice.bin
8 opt/openoffice.org3/program/unopkg.bin
8 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/crypt.so
10 opt/openoffice.org/ure/bin/regmerge
10 opt/openoffice.org/ure/bin/regview
10 opt/openoffice.org/ure/lib/libgcc_s.so.1
11 opt/openoffice.org/basis3.0/program/libcollator_data.so
11 opt/openoffice.org/basis3.0/program/libdict_ja.so
11 opt/openoffice.org/basis3.0/program/libdict_zh.so
11 opt/openoffice.org/basis3.0/program/liberali.so
11 opt/openoffice.org/basis3.0/program/libetili.so
11 opt/openoffice.org/basis3.0/program/libexpli.so
11 opt/openoffice.org/basis3.0/program/libicdli.so
11 opt/openoffice.org/basis3.0/program/libimeli.so
11 opt/openoffice.org/basis3.0/program/libipbli.so
11 opt/openoffice.org/basis3.0/program/libipdli.so
11 opt/openoffice.org/basis3.0/program/libipsli.so
11 opt/openoffice.org/basis3.0/program/libiptli.so
11 opt/openoffice.org/basis3.0/program/libipxli.so
11 opt/openoffice.org/basis3.0/program/libirali.so
11 opt/openoffice.org/basis3.0/program/libitgli.so
11 opt/openoffice.org/basis3.0/program/libofficebean.so
11 opt/openoffice.org/basis3.0/program/libtextconv_dict.so
11 opt/openoffice.org/ure/bin/javaldx
11 opt/openoffice.org/ure/lib/libjpipe.so
12 opt/openoffice.org/ure/bin/regcomp.bin
13 opt/openoffice.org/basis3.0/program/gengal.bin
13 opt/openoffice.org/basis3.0/program/libaggli.so
13 opt/openoffice.org/basis3.0/program/nsplugin
14 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/rgbimg.so
14 opt/openoffice.org/ure/bin/uno.bin
15 opt/openoffice.org/basis3.0/program/libitili.so
15 opt/openoffice.org/basis3.0/program/pluginapp.bin
15 opt/openoffice.org/basis3.0/program/spadmin.bin
16 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/timing.so
16 opt/openoffice.org/ure/lib/libjuh.so
17 opt/openoffice.org/basis3.0/program/libplds4.so
18 opt/openoffice.org/basis3.0/program/libi18nregexpgcc3.so
18 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/syslog.so
19 opt/openoffice.org/ure/lib/librmcxt.so.3
20 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_weakref.so
21 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/fcntl.so
22 opt/openoffice.org/basis3.0/program/libi18nisolang1gcc3.so
22 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/dl.so
23 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/rotor.so
24 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/xreadlines.so
27 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/grp.so
27 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/nis.so
27 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/pcre.so
28 opt/openoffice.org3/program/libnpsoplugin.so
29 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/md5.so
29 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/sha.so
30 opt/openoffice.org/basis3.0/program/fpicker.uno.so
30 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/select.so
32 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_random.so
33 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/pwd.so
33 opt/openoffice.org/basis3.0/program/pythonloader.uno.so
34 opt/openoffice.org/basis3.0/program/desktopbe1.uno.so
34 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_ssl.so
35 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/dbm.so
35 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/imageop.so
37 opt/openoffice.org/basis3.0/program/libindex_data.so
38 opt/openoffice.org/basis3.0/program/libjli_g.so
38 opt/openoffice.org/basis3.0/program/libmozz.so
40 opt/openoffice.org/ure/lib/libuno_salhelpergcc3.so.3
41 opt/openoffice.org/basis3.0/program/libi18nutilgcc3.so
42 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/gdbm.so
42 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/linuxaudiodev.so
42 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/regex.so
44 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/zlib.so
45 opt/openoffice.org/basis3.0/program/libbf_ofali.so
46 opt/openoffice.org/ure/lib/libunsafe_uno_uno.so
47 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_testcapi.so
47 opt/openoffice.org/ure/lib/libuno_cppu.so.3
51 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/resource.so
52 opt/openoffice.org/ure/lib/libjvmfwk.so.3
54 opt/openoffice.org/basis3.0/program/components/libvcard.so
54 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/time.so
54 opt/openoffice.org/ure/lib/libuno_purpenvhelpergcc3.so.3
55 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/audioop.so
55 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/cmath.so
55 opt/openoffice.org/basis3.0/program/testtool.bin
58 opt/openoffice.org/ure/lib/libgcc3_uno.so
60 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/mmap.so
62 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/binascii.so
63 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/mpz.so
66 opt/openoffice.org/basis3.0/program/libbf_goli.so
66 opt/openoffice.org/ure/lib/libjava_uno.so
69 opt/openoffice.org/ure/lib/libjvmaccessgcc3.so.3
76 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/strop.so
81 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_csv.so
86 opt/openoffice.org/basis3.0/program/librdf.so.0.0.0
86 opt/openoffice.org/ure/lib/libaffine_uno_uno.so
87 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_hotshot.so
89 opt/openoffice.org/basis3.0/program/libplc4.so
91 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/parser.so
97 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/cPickle.so
97 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_locale.so
97 opt/openoffice.org/ure/lib/libreg.so.3
98 opt/openoffice.org/basis3.0/program/libxslt.so.1.1.24
100 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/struct.so
103 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/math.so
116 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/bz2.so
116 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/cStringIO.so
125 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/ossaudiodev.so
128 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/itertools.so
132 opt/openoffice.org/basis3.0/program/libcurl.so.3.0.0
133 opt/openoffice.org/basis3.0/program/libldap50.so
145 opt/openoffice.org/basis3.0/program/libicgli.so
151 opt/openoffice.org/ure/lib/liburp_uno.so
152 opt/openoffice.org/basis3.0/program/libtfuli.so
152 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/array.so
153 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_socket.so
161 opt/openoffice.org/ure/lib/namingservice.uno.so
163 opt/openoffice.org/basis3.0/program/libepbli.so
163 opt/openoffice.org/basis3.0/program/libepgli.so
163 opt/openoffice.org/basis3.0/program/libeppli.so
164 opt/openoffice.org/basis3.0/program/libegili.so
164 opt/openoffice.org/ure/lib/remotebridge.uno.so
166 opt/openoffice.org/basis3.0/program/libemeli.so
166 opt/openoffice.org/basis3.0/program/libeptli.so
168 opt/openoffice.org/ure/lib/uuresolver.uno.so
169 opt/openoffice.org/basis3.0/program/libsmdli.so
170 opt/openoffice.org/basis3.0/program/i18nsearch.uno.so
170 opt/openoffice.org/basis3.0/program/libswdli.so
171 opt/openoffice.org/basis3.0/program/libsddli.so
171 opt/openoffice.org/basis3.0/program/syssh.uno.so
173 opt/openoffice.org/ure/lib/javaloader.uno.so
175 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/unicodedata.so
182 opt/openoffice.org/basis3.0/program/ucpexpand1.uno.so
185 opt/openoffice.org/basis3.0/program/libmozabli.so
187 opt/openoffice.org/basis3.0/program/libxmlfdli.so
188 opt/openoffice.org/ure/lib/invocadapt.uno.so
189 opt/openoffice.org/ure/lib/proxyfac.uno.so
191 opt/openoffice.org/basis3.0/program/libscdli.so
198 opt/openoffice.org/basis3.0/program/canvasfactory.uno.so
199 opt/openoffice.org/basis3.0/program/behelper.uno.so
199 opt/openoffice.org/basis3.0/program/libsimplecmli.so
201 opt/openoffice.org/basis3.0/program/libodbcli.so
208 opt/openoffice.org/ure/lib/textoutstream.uno.so
210 opt/openoffice.org/basis3.0/program/libcommunili.so
212 opt/openoffice.org/basis3.0/program/libguesslangli.so
214 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_bsddb.so
218 opt/openoffice.org/ure/lib/bridgefac.uno.so
220 opt/openoffice.org/basis3.0/program/components/libxpcom_compat_c.so
221 opt/openoffice.org/basis3.0/program/libidxli.so
221 opt/openoffice.org/ure/lib/libjuhx.so
227 opt/openoffice.org/basis3.0/program/libplacewareli.so
233 opt/openoffice.org/ure/lib/sunjavaplugin.so
237 opt/openoffice.org/basis3.0/program/liboffaccli.so
238 opt/openoffice.org/basis3.0/program/libxmxli.so
240 opt/openoffice.org/basis3.0/program/libepsli.so
241 opt/openoffice.org/ure/lib/textinstream.uno.so
242 opt/openoffice.org/basis3.0/program/libkab1.so
242 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/operator.so
245 opt/openoffice.org/basis3.0/program/components/libprofile.so
245 opt/openoffice.org/basis3.0/program/libmcnttype.so
246 opt/openoffice.org/basis3.0/program/libprotocolhandlerli.so
249 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/termios.so
251 opt/openoffice.org/basis3.0/program/libsmime3.so
252 opt/openoffice.org/basis3.0/program/localebe1.uno.so
253 opt/openoffice.org/basis3.0/program/sysmgr1.uno.so
257 opt/openoffice.org/basis3.0/program/libbf_migratefilterli.so
262 opt/openoffice.org/basis3.0/program/libssl3.so
266 opt/openoffice.org/basis3.0/program/librecentfile.so
284 opt/openoffice.org/basis3.0/program/liboooimprovecoreli.so
284 opt/openoffice.org/basis3.0/program/libvclplug_kdeli.so
297 opt/openoffice.org/basis3.0/program/libsaxli.so
303 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/datetime.so
310 opt/openoffice.org/basis3.0/program/libbindetli.so
318 opt/openoffice.org/basis3.0/program/libxmlfali.so
323 opt/openoffice.org/basis3.0/program/libpyuno.so
323 opt/openoffice.org/basis3.0/program/libsolverli.so
337 opt/openoffice.org/basis3.0/program/libxsltfilterli.so
347 opt/openoffice.org/basis3.0/program/libdb-4.2.so
348 opt/openoffice.org/ure/lib/connector.uno.so
352 opt/openoffice.org/basis3.0/program/cmdmail.uno.so
354 opt/openoffice.org/basis3.0/program/gconfbe1.uno.so
356 opt/openoffice.org/ure/lib/acceptor.uno.so
357 opt/openoffice.org/basis3.0/program/libbasegfxli.so
361 opt/openoffice.org/basis3.0/program/libsdbc2.so
373 opt/openoffice.org/basis3.0/program/libfwlli.so
375 opt/openoffice.org/basis3.0/program/passwordcontainer.uno.so
376 opt/openoffice.org/basis3.0/program/libbf_wrapperli.so
386 opt/openoffice.org/basis3.0/program/libdeploymentmiscli.so
388 opt/openoffice.org/basis3.0/program/libupdchkli.so
389 opt/openoffice.org/basis3.0/program/kdebe1.uno.so
393 opt/openoffice.org/basis3.0/program/libt602filterli.so
394 opt/openoffice.org/basis3.0/program/libhelplinkerli.so
395 opt/openoffice.org/basis3.0/program/libevtatt.so
408 opt/openoffice.org/basis3.0/program/productregistration.uno.so
410 opt/openoffice.org/basis3.0/program/libunopkgapp.so
415 opt/openoffice.org/basis3.0/program/libsvgfilterli.so
419 opt/openoffice.org/basis3.0/program/components/libmozldap.so
419 opt/openoffice.org/basis3.0/program/librasqal.so.0.0.0
422 opt/openoffice.org/basis3.0/program/libhyphenli.so
429 opt/openoffice.org/basis3.0/program/libdateli.so
432 opt/openoffice.org/basis3.0/program/libxpcom_compat.so
438 opt/openoffice.org/basis3.0/program/libucppkg1.so
461 opt/openoffice.org/basis3.0/program/simplecanvas.uno.so
465 opt/openoffice.org/basis3.0/program/liblnthli.so
468 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/pyexpat.so
472 opt/openoffice.org/basis3.0/program/libresli.so
478 opt/openoffice.org/ure/lib/invocation.uno.so
493 opt/openoffice.org/basis3.0/program/libpreloadli.so
496 opt/openoffice.org/basis3.0/program/ucpgvfs1.uno.so
497 opt/openoffice.org/basis3.0/program/libraptor.so.1.1.0
499 opt/openoffice.org/basis3.0/program/migrationoo2.uno.so
502 opt/openoffice.org/basis3.0/program/libicule.so.40.0
502 opt/openoffice.org/basis3.0/program/libspellli.so
503 opt/openoffice.org/basis3.0/program/components/libpref.so
507 opt/openoffice.org/ure/lib/libstore.so.3
524 opt/openoffice.org/basis3.0/program/fastsax.uno.so
543 opt/openoffice.org/basis3.0/program/ldapbe2.uno.so
547 opt/openoffice.org/basis3.0/program/libfileacc.so
553 opt/openoffice.org/basis3.0/program/updatefeed.uno.so
557 opt/openoffice.org/basis3.0/program/libnspr4.so
571 opt/openoffice.org/basis3.0/program/liblpsolve55.so
574 opt/openoffice.org/basis3.0/program/libdbacfgli.so
586 opt/openoffice.org/basis3.0/program/libtvhlp1.so
590 opt/openoffice.org/ure/lib/javavm.uno.so
592 opt/openoffice.org/basis3.0/program/libforli.so
593 opt/openoffice.org/basis3.0/program/basprovli.uno.so
597 opt/openoffice.org/basis3.0/program/libsrtrs1.so
599 opt/openoffice.org/ure/lib/introspection.uno.so
615 opt/openoffice.org/basis3.0/program/libfwmli.so
623 opt/openoffice.org/basis3.0/program/hatchwindowfactory.uno.so
624 opt/openoffice.org/basis3.0/program/libvos3gcc3.so
627 opt/openoffice.org/basis3.0/program/libvclplug_svpli.so
630 opt/openoffice.org/basis3.0/program/libadabasuili.so
644 opt/openoffice.org/basis3.0/program/libscnli.so
664 opt/openoffice.org/basis3.0/program/libbasebmpli.so
681 opt/openoffice.org/basis3.0/program/libvclplug_gtkli.so
685 opt/openoffice.org/basis3.0/program/libfwili.so
687 opt/openoffice.org/basis3.0/program/dlgprovli.uno.so
697 opt/openoffice.org/basis3.0/program/libucphier1.so
713 opt/openoffice.org/basis3.0/program/libflashli.so
725 opt/openoffice.org/basis3.0/program/fsstorage.uno.so
752 opt/openoffice.org/basis3.0/program/libdbpool2.so
752 opt/openoffice.org/basis3.0/program/sax.uno.so
780 opt/openoffice.org/basis3.0/program/libempli.so
784 opt/openoffice.org/basis3.0/program/fps_gnome.uno.so
790 opt/openoffice.org/basis3.0/program/libtextconversiondlgsli.so
833 opt/openoffice.org/basis3.0/program/updchk.uno.so
837 opt/openoffice.org/basis3.0/program/libcanvastoolsli.so
843 opt/openoffice.org/basis3.0/program/libsdbtli.so
850 opt/openoffice.org/basis3.0/program/libgoli.so
880 opt/openoffice.org/basis3.0/program/svtmisc.uno.so
886 opt/openoffice.org/basis3.0/program/libscriptframe.so
902 opt/openoffice.org/basis3.0/program/liblogli.so
906 opt/openoffice.org/ure/lib/reflection.uno.so
925 opt/openoffice.org/basis3.0/program/libanalysisli.so
971 opt/openoffice.org/basis3.0/program/libsoftokn3.so
979 opt/openoffice.org/basis3.0/program/libpdffilterli.so
984 opt/openoffice.org/basis3.0/program/libemboleobj.so
999 opt/openoffice.org/basis3.0/program/libabpli.so
999 opt/openoffice.org/basis3.0/program/libnss3.so
1006 opt/openoffice.org/basis3.0/program/libtlli.so
1018 opt/openoffice.org/basis3.0/program/liblegacy_binfiltersli.so
1046 opt/openoffice.org/basis3.0/program/stocservices.uno.so
1046 opt/openoffice.org/ure/lib/stocservices.uno.so
1068 opt/openoffice.org/basis3.0/program/libavmediali.so
1076 opt/openoffice.org/basis3.0/program/libucpftp1.so
1134 opt/openoffice.org/basis3.0/program/components/librdf.so
1134 opt/openoffice.org/basis3.0/program/libunordfli.so
1139 opt/openoffice.org/basis3.0/program/libfilterconfig1.so
1179 opt/openoffice.org/basis3.0/program/libdtransX11li.so
1193 opt/openoffice.org/basis3.0/program/libdbaxmlli.so
1229 opt/openoffice.org/basis3.0/program/libdbmmli.so
1249 opt/openoffice.org/basis3.0/program/ucptdoc1.uno.so
1287 opt/openoffice.org/basis3.0/program/libforuili.so
1305 opt/openoffice.org/basis3.0/program/libcached1.so
1310 opt/openoffice.org/basis3.0/program/libsplli.so
1318 opt/openoffice.org/basis3.0/program/stringresourceli.uno.so
1362 opt/openoffice.org/basis3.0/program/libstsli.so
1363 opt/openoffice.org/basis3.0/program/libmozjs.so
1368 opt/openoffice.org/basis3.0/program/libucpchelp1.so
1381 opt/openoffice.org/basis3.0/program/components/libi18n.so
1400 opt/openoffice.org/basis3.0/program/libucb1.so
1435 opt/openoffice.org/basis3.0/program/libucpfile1.so
1447 opt/openoffice.org/basis3.0/program/libpspli.so
1483 opt/openoffice.org/basis3.0/program/libxstor.so
1484 opt/openoffice.org/ure/lib/streams.uno.so
1499 opt/openoffice.org/basis3.0/program/libmysqlli.so
1510 opt/openoffice.org/basis3.0/program/libchartviewli.so
1546 opt/openoffice.org/basis3.0/program/libembobj.so
1586 opt/openoffice.org/basis3.0/program/components/libpipnss.so
1589 opt/openoffice.org/basis3.0/program/libcppcanvasli.so
1644 opt/openoffice.org/basis3.0/program/libplli.so
1669 opt/openoffice.org/basis3.0/program/libsotli.so
1669 opt/openoffice.org/basis3.0/program/libxsltdlgli.so
1697 opt/openoffice.org/basis3.0/program/libhwp.so
1697 opt/openoffice.org/basis3.0/program/libsofficeapp.so
1699 opt/openoffice.org/ure/lib/libstlport_gcc.so
1717 opt/openoffice.org/basis3.0/program/libxofli.so
1721 opt/openoffice.org/basis3.0/program/libxsec_fw.so
1726 opt/openoffice.org/basis3.0/program/components/libmork.so
1798 opt/openoffice.org/basis3.0/program/libctlli.so
1806 opt/openoffice.org/ure/lib/libuno_cppuhelpergcc3.so.3
1820 opt/openoffice.org/basis3.0/program/libvclplug_genli.so
1828 opt/openoffice.org/basis3.0/program/libuuili.so
1837 opt/openoffice.org/basis3.0/program/fps_office.uno.so
1869 opt/openoffice.org/basis3.0/program/libmsgbaseutil.so
1926 opt/openoffice.org/basis3.0/program/libxsec_xmlsec.so
1941 opt/openoffice.org/basis3.0/program/libfweli.so
1960 opt/openoffice.org/basis3.0/program/libflatli.so
1995 opt/openoffice.org/basis3.0/program/libevoabli.so
1996 opt/openoffice.org/basis3.0/program/libcalcli.so
2010 opt/openoffice.org/basis3.0/program/libdbpli.so
2011 opt/openoffice.org/basis3.0/program/libxmlsecurity.so
2057 opt/openoffice.org/basis3.0/program/libucbhelper4gcc3.so
2062 opt/openoffice.org/basis3.0/program/components/libxpconnect.so
2064 opt/openoffice.org/basis3.0/program/libpackage2.so
2129 opt/openoffice.org/basis3.0/program/libhsqldb.so
2168 opt/openoffice.org/basis3.0/program/libanimcore.so
2276 opt/openoffice.org/basis3.0/program/components/libuconv.so
2311 opt/openoffice.org/basis3.0/program/libspali.so
2327 opt/openoffice.org/basis3.0/program/libmswordli.so
2408 opt/openoffice.org/basis3.0/program/deploymentguili.uno.so
2432 opt/openoffice.org/basis3.0/program/libdbaseli.so
2457 opt/openoffice.org/basis3.0/program/libbibli.so
2460 opt/openoffice.org/ure/lib/libstdc++.so.6
2694 opt/openoffice.org/basis3.0/program/libutlli.so
2865 opt/openoffice.org/basis3.0/program/libodbcbaseli.so
2928 opt/openoffice.org/basis3.0/program/libwpftli.so
3029 opt/openoffice.org/basis3.0/program/libbf_smli.so
3104 opt/openoffice.org/basis3.0/program/libxcrli.so
3198 opt/openoffice.org/ure/lib/libxml2.so.2
3233 opt/openoffice.org/basis3.0/program/libsvlli.so
3245 opt/openoffice.org/basis3.0/program/components/libaddrbook.so
3287 opt/openoffice.org/basis3.0/program/libkabdrv1.so
3337 opt/openoffice.org/basis3.0/program/liblngli.so
3357 opt/openoffice.org/basis3.0/program/libmozabdrvli.so
3432 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_curses_panel.so
3445 opt/openoffice.org/basis3.0/program/libadabasli.so
3730 opt/openoffice.org/basis3.0/program/libjdbcli.so
3784 opt/openoffice.org/basis3.0/program/libicui18n.so.40.0
3821 opt/openoffice.org/basis3.0/program/libdrawinglayerli.so
3906 opt/openoffice.org/basis3.0/program/libfileli.so
3970 opt/openoffice.org/basis3.0/program/libsduili.so
4075 opt/openoffice.org/basis3.0/program/libpython2.3.so.1.0
4097 opt/openoffice.org/basis3.0/program/deploymentli.uno.so
4150 opt/openoffice.org/basis3.0/program/libicuuc.so.40.0
4302 opt/openoffice.org/basis3.0/program/libxpcom.so
4319 opt/openoffice.org/basis3.0/program/liblocaledata_es.so
4502 opt/openoffice.org/basis3.0/program/liblocaledata_en.so
4663 opt/openoffice.org/ure/lib/libuno_sal.so.3
4676 opt/openoffice.org/ure/lib/bootstrap.uno.so
4722 opt/openoffice.org/basis3.0/program/components/libnecko.so
4982 opt/openoffice.org/basis3.0/program/libbf_soli.so
5013 opt/openoffice.org/basis3.0/program/libcharttoolsli.so
5256 opt/openoffice.org/basis3.0/program/libsmli.so
5374 opt/openoffice.org/basis3.0/program/python-core-2.3.4/lib/lib-dynload/_curses.so
5540 opt/openoffice.org/basis3.0/program/libbf_sbli.so
5811 opt/openoffice.org/basis3.0/program/slideshow.uno.so
6012 opt/openoffice.org/basis3.0/program/libbf_schli.so
6353 opt/openoffice.org/basis3.0/program/vclcanvas.uno.so
6481 opt/openoffice.org/basis3.0/program/libunoxmlli.so
6551 opt/openoffice.org/basis3.0/program/libscuili.so
6667 opt/openoffice.org/basis3.0/program/libscfiltli.so
6725 opt/openoffice.org/basis3.0/program/libcomphelp4gcc3.so
6730 opt/openoffice.org/basis3.0/program/libbf_sdli.so
6982 opt/openoffice.org/basis3.0/program/libbf_svtli.so
7116 opt/openoffice.org/basis3.0/program/libdbtoolsli.so
7671 opt/openoffice.org/basis3.0/program/libbasctlli.so
8414 opt/openoffice.org/basis3.0/program/libchartmodelli.so
9782 opt/openoffice.org/basis3.0/program/libpcrli.so
10042 opt/openoffice.org/basis3.0/program/libsbli.so
10240 opt/openoffice.org/basis3.0/program/libucpdav1.so
11268 opt/openoffice.org/basis3.0/program/i18npool.uno.so
11559 opt/openoffice.org/basis3.0/program/libvclli.so
11657 opt/openoffice.org/basis3.0/program/libfwkli.so
11915 opt/openoffice.org/basis3.0/program/libaccli.so
11976 opt/openoffice.org/basis3.0/program/libbf_xoli.so
12568 opt/openoffice.org/basis3.0/program/libchartcontrollerli.so
13352 opt/openoffice.org/basis3.0/program/configmgr2.uno.so
14279 opt/openoffice.org/basis3.0/program/libbf_frmli.so
15504 opt/openoffice.org/basis3.0/program/libxoli.so
16083 opt/openoffice.org/basis3.0/program/libdbali.so
16440 opt/openoffice.org/basis3.0/program/libswuili.so
18793 opt/openoffice.org/basis3.0/program/libvbaobjli.uno.so
19218 opt/openoffice.org/basis3.0/program/libcuili.so
19950 opt/openoffice.org/basis3.0/program/libsfxli.so
21368 opt/openoffice.org/basis3.0/program/libbf_scli.so
24233 opt/openoffice.org/basis3.0/program/libsvtli.so
25860 opt/openoffice.org/basis3.0/program/libfrmli.so
26811 opt/openoffice.org/basis3.0/program/libbf_swli.so
27025 opt/openoffice.org/basis3.0/program/libdbuli.so
31017 opt/openoffice.org/basis3.0/program/liblocaledata_euro.so
31950 opt/openoffice.org/basis3.0/program/libooxli.so
32073 opt/openoffice.org/basis3.0/program/libbf_svxli.so
35190 opt/openoffice.org/basis3.0/program/liblocaledata_others.so
40816 opt/openoffice.org/basis3.0/program/libtkli.so
46714 opt/openoffice.org/basis3.0/program/libsdli.so
49694 opt/openoffice.org/basis3.0/program/libscli.so
61034 opt/openoffice.org/basis3.0/program/libwriterfilterli.so
61287 opt/openoffice.org/basis3.0/program/libswli.so
84341 opt/openoffice.org/basis3.0/program/libsvxli.so

Measurements

Measurements are done on a Sun Ultra 20 with a recent (as of February 25, 2009) Debian Unstable i386. The OOo is a sb107/DEV300/src.m41/instsetoo_native/unxlngi6.pro/OpenOffice/archive/install/en-US/OOo_3.0.0_090219_unxlngi6_install.tar.gz (i.e., CWS sb107 as based on DEV300m41 with just a fix for Issue 99519 included), installed to /sb-tree1/ooo-m107 with UserInstallation=file:///sb-tree2/ooo-m107/.openoffice.org/3 in /sb-tree1/ooo-m107/openoffice.org3/program/bootstraprc, “Check for updates automatically” disabled, “I do not want to register” selected (both during first soffice start), and “No, I do not wish to participate” selected (during second soffice start); the working directory is /sb-tree3.

During soffice.bin start up, vcl/unx/source/fontmanager/fontconfig.cxx l. 791 calls FcConfigAppFontAddDir three times (with existing directory /opt/openoffice.org/basis3.2/share/fonts/truetype and non-existing directories /opt/openoffice.org3/program/../basis-link/share/fonts/type1 and ~/.openoffice.org/3/user/fonts). Apparently, during the first soffice start those directories are actually accessed and data about them stored at ~/.fontconfig (resulting in heavy use of the freetype dynamic library), while during subsequent starts the cached data is used.

time

Just after system start up run

$ cd /sb-tree3
$ time /sb-tree1/ooo-sb107/openoffice.org3/program/soffice -swriter # press Ctrl-Q as soon as the text cursor starts to blink
$ time /sb-tree1/ooo-sb107/openoffice.org3/program/soffice -swriter # press Ctrl-Q as soon as the text cursor starts to blink
$ time /sb-tree1/ooo-sb107/openoffice.org3/program/soffice -swriter # press Ctrl-Q as soon as the text cursor starts to blink

to get one cold and two warm start-up (plus shut-down) times. Repeat three times. The average of the three cold start ups is

real 0m11.584s
user 0m2.335s
sys  0m0.237s

and the average of the six warm start ups is

real 0m3.528s
user 0m2.069s
sys  0m0.173s

strace

Just after system start up run

$ cd /sb-tree3
$ strace -ff -T -o ~/cold /sb-tree1/ooo-sb107/openoffice.org3/program/soffice -swriter # press Ctrl-Q as soon as the text cursor starts to blink
$ strace -ff -T -o ~/warma /sb-tree1/ooo-sb107/openoffice.org3/program/soffice -swriter # press Ctrl-Q as soon as the text cursor starts to blink
$ strace -ff -T -o ~/warmb /sb-tree1/ooo-sb107/openoffice.org3/program/soffice -swriter # press Ctrl-Q as soon as the text cursor starts to blink

to get one cold and two warm start-up (plus shut-down) times. Repeat three times (cold1cold3, warm1awarm3b). Use

$ for i in cold1.*; do sed "s/^/${i#cold1.} /" "$i"; done | strace-eval > cold1-all

(and similarly for the other measurements) with the following strace-eval Haskell script

-- Makefile:
--  .PHONY: strace-eval
--  strace-eval:
--   ghc-6.10.1 --make -o $@ Main.hs
--
-- Group strace output system calls by files they operate on:
--
-- $ strace -T -o log1 soffice.bin && strace-eval < log1 > log2
--
-- or
--
-- $ strace -ff -T -o log1 soffice && \
--    for i in log1.*; do sed "s/^/${i#log1.} /" "$i"; done | strace-eval > log2
 
{-# LANGUAGE ScopedTypeVariables #-}
 
module Main (main) where
 
import Data.Map as M
import GHC.Exts (sortWith)
import Text.Regex.Posix ((=~))
 
main :: IO ()
main = do c <- getContents
          let cs = lines c
          let m = process M.empty M.empty cs
          mapM_ displayFileData $ reverse $ sortWith (fst . snd) $ M.toList m
 
type FdMap = M.Map (String, Integer) String -- (pid, fd) -> filepath
 
type FileMap = M.Map FileSpec FileData
 
data FileSpec = File String
              | Fd String Integer -- pid, fd
              | Unknown deriving (Eq, Ord)
 
type FileData = (Integer, [String]) -- (time, [lines])
 
process :: FdMap -> FileMap -> [String] -> FileMap
process _ fm [] = fm
process fdm fm (c:cs) = process fdm' fm' cs
    where (fdm', fm') = processOne fdm fm c
 
processOne :: FdMap -> FileMap -> String -> (FdMap, FileMap)
processOne fdm fm c = case splitLine c of
                        Just (pid, s, a, r, n) ->
                            (fdm', M.insertWith merge fs (n, [c]) fm)
                            where (fdm', fs) = parse fdm pid s a r
                        _ ->
                            (fdm, M.insertWith merge Unknown (0, [c]) fm)
    where merge (n', cs') (n, cs) = (n + n', cs ++ cs')
 
splitLine :: String -> Maybe (String, String, String, String, Integer)
splitLine c = case pts of
                [pid, s, a, r, n1, n2] ->
                    Just (pid, s, a, r, 1000000 * read n1 + read n2)
                _ -> Nothing
    where pts = c =~~~ "^([0-9]+)? *([0-9A-Z_a-z]+)\\((.*)\\) += (.+) <([0-9]+)\\.([0-9][0-9][0-9][0-9][0-9][0-9])>$"
 
parse :: FdMap -> String -> String -> String -> String -> (FdMap, FileSpec)
parse fdm pid "_llseek" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "accept" a r = case (a', r') of
                           (_, [fd]) -> (fdm, Fd pid $ read fd)
                           ([fd], _) -> (fdm, findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
          r' = r =~~~ "^([0-9]+)$"
parse fdm pid "access" a _ = (fdm, case a' of { (f:_) -> File f; _ -> Unknown })
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\"" -- or "^NULL"
parse fdm pid "bind" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "chdir" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\"$"
parse fdm pid "chmod" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\","
parse fdm pid "chown32" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\","
parse fdm pid "close" a r =
    case (a', r') of
      ([fd], ["0"]) -> (M.delete (pid, read fd) fdm, findFile fdm pid $ read fd)
      ([fd], _) -> (fdm, findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+)$"
          r' = r =~~~ "^([0-9]+)$"
parse fdm pid "connect" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "execve" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "fcntl64" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "fstat64" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "fsync" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+)$"
parse fdm pid "ftruncate" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "ftruncate64" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "getcwd" a _ = (fdm, case a' of { (f:_) -> File f; _ -> Unknown })
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\"" -- or "^NULL"
parse fdm pid "getdents64" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "getpeername" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "getsockname" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "ioctl" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "link" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "listen" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "lseek" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "lstat64" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "mkdir" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "mmap2" a _ =
    (fdm,
     case a' of ["-1"] -> Unknown
                [fd] -> findFile fdm pid $ read fd
                _ -> error a)
    where a' = a =~~~ ", (-?[0-9]+), -?[0-9a-fx]+$"
parse fdm pid "old_mmap" a _ =
    (fdm,
     case a' of ["-1"] -> Unknown
                [fd] -> findFile fdm pid $ read fd
                _ -> error a)
    where a' = a =~~~ ", (-?[0-9]+), -?[0-9a-fx]+$"
parse fdm pid "open" a r =
    case (a', r') of
      (f:_, [fd]) -> (M.insertWith (error ("not empty <"++pid++"/"++fd++", "++a++", "++r++">") . const) (pid, read fd) f
                       fdm,
                      File f)
      (f:_, _) -> (fdm, File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
          r' = r =~~~ "^([0-9]+)$"
parse fdm pid "pipe" a r =
    (fdm,
     case (a', r) of ([fd, _], "0") -> findFile fdm pid $ read fd
                     _ -> Unknown)
    where a' = a =~~~ "^\\[([0-9]+), ([0-9]+)\\]$"
parse fdm pid "poll" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd) --TODO
    where a' = a =~~~ "^\\[\\{fd=([0-9]+),"
parse fdm pid "pread64" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "pwrite64" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "read" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "readlink" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "readv" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "recv" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "recvmsg" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "rename" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "rmdir" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "send" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "setsockopt" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "shutdown" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "socket" a r =
    case r' of
      [fd] -> (fdm, Fd pid $ read fd)
      _ -> (fdm, Unknown)
    where r' = r =~~~ "^([0-9]+)$"
parse fdm pid "stat64" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "unlink" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "utime" a _ = (fdm, case a' of (f:_) -> File f)
    where a' = a =~~~ "^\"(([^\"\\]|\\\\.)*)\""
parse fdm pid "write" a _ = (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid "writev" a _ =
    (fdm, case a' of [fd] -> findFile fdm pid $ read fd)
    where a' = a =~~~ "^([0-9]+),"
parse fdm pid _ _ _ = (fdm, Unknown)
 
(=~~~) :: String -> String -> [String]
a =~~~ b = c
    where (_::String, _::String, _::String, c) = a =~ b
 
displayFileData :: (FileSpec, FileData) -> IO ()
displayFileData (_, (0, [])) = return ()
displayFileData (s, (n, cs)) = do
  putStrLn $ showSpec s ++ ": " ++ show n ++ "mu"
  mapM_ (putStrLn . ("  " ++)) $ cs
 
showSpec :: FileSpec -> String
showSpec Unknown = "???"
showSpec (Fd pid fd) = (if pid == "" then "" else pid ++ "/") ++ show fd
showSpec (File f) = "\"" ++ f ++ "\""
 
findFile :: FdMap -> String -> Integer -> FileSpec
findFile fdm pid fd = case M.lookup (pid, fd) fdm of
                        Just f -> File f
                        Nothing -> Fd pid fd

to group system calls by the files or file descriptors they work on. The output is a list of blocks, sorted descending on time spent. Each block consists of a start line consisting of a file tag, a colon, a space, and an accumulated time, followed by one or more lines (pertaining to the given file tag) from the (combined, in the case of strace -ff -o) original strace output (in original order), each prefixed with a space. A file tag is either a filepath in double quotes, or a pid/fd combination of numeric pid and fd (for uses of file descriptors that cannot be associated with a filepath; the “pid/” part is left out for strace calls without -ff), or ??? for all system calls that are not associated with a filepath or file descriptor at all. The accumulated time is the sum of the times given by strace -T for the individual lines, measured in microseconds.

For the measured times, take the following into account:

  • The description of the -O option on the man page of strace(1) makes you assume that the given numbers are not too accurate.
  • In multi-threaded scenarios, large times for certain system calls naturally need not imply delays in start up (if those delays are compensated for by other threads making progress).
  • Similarly, in multi-process scenarios, large times for certain system calls naturally need not imply delays in start up either (if those delays are compensated for by other processes making progress; this is especially true for large times given for wait-family system calls that are accumulated under the ??? file tag).

The resulting measurements do exhibit some variance, but concentrating on the top listed files (i.e., filtering out mere file descriptors and ???) across cold and warm starts does show trends:

  • Accessing the four Berkeley DB files of the extension manager is costly due to fsync system calls. However, the costly flush calls are only made during OOo shut-down, not during start-up. Typical numbers are for example
"/sb-tree2/ooo-sb107/.openoffice.org/3/user/uno_packages/cache/registry/com.sun.star.comp.deployment.configuration.PackageRegistryBackend/registered_packages.db": 167833mu
"/sb-tree1/ooo-sb107/openoffice.org3/program/../share/uno_packages/cache/uno_packages.db": 58392mu
"/sb-tree1/ooo-sb107/openoffice.org3/program/../share/uno_packages/cache/registry/com.sun.star.comp.deployment.configuration.PackageRegistryBackend/registered_packages.db": 49750mu
"/sb-tree2/ooo-sb107/.openoffice.org/3/user/uno_packages/cache/uno_packages.db": 41407mu
  • Accessing images_tango.zip is costly due to many small read system calls. Typical numbers are for example
"/sb-tree1/ooo-sb107/openoffice.org3/program/../basis-link/share/config/images_tango.zip": 119944mu

for cold start and

"/sb-tree1/ooo-sb107/openoffice.org3/program/../basis-link/share/config/images_tango.zip": 18541mu

for warm start.

  • Accessing the directories of the OOo installation is costyl due to many repeated stat-family system calls. Typical numbers are for example
"/sb-tree1": 21751mu
"/sb-tree1/ooo-sb107": 18782mu
"/sb-tree1/ooo-sb107/openoffice.org3": 9481mu
"/sb-tree1/ooo-sb107/openoffice.org3/basis-link": 2640mu
"/sb-tree1/ooo-sb107/openoffice.org3/program": 5238mu
"/sb-tree1/ooo-sb107/openoffice.org3/program/../basis-link/program": 29mu

for cold start and

"/sb-tree1": 22727mu
"/sb-tree1/ooo-sb107": 19496mu
"/sb-tree1/ooo-sb107/openoffice.org3": 9811mu
"/sb-tree1/ooo-sb107/openoffice.org3/basis-link": 2742mu
"/sb-tree1/ooo-sb107/openoffice.org3/program": 5413mu
"/sb-tree1/ooo-sb107/openoffice.org3/program/../basis-link/program": 15mu

for warm start.

callgrind

Run

$ cp -a /sb-tree1 /sb-tree1f
$ unstr /cws/so-cwsserv02/sb107/DEV300/scr.m41 /cws/so-cwsserv02/sb107/DEV300/unxlngi6.pro/inc.m41 /sb-tree1f/ooo-sb107

once to get an unstripped OOo installation, using the following unstr Haskell script:

-- Makefile:
--  .PHONY: unstr
--  unstr:
--   ghc-6.10.1 --make -o $@ Main.hs
--
-- Replace ELF objects in an OOo installation with unstripped ones from a build
-- tree:
--
-- $ unstr <build-tree-root> <solver-inc-dir> <installation-root>
 
module Main (main) where
 
import Control.Monad (filterM, foldM, join, zipWithM_)
import Data.List (isPrefixOf)
import Data.Map (Map, empty, foldWithKey, insertWith)
import qualified Data.Map (lookup)
import System.Directory (copyFile, doesFileExist, getDirectoryContents)
import System.Environment (getArgs)
import System.Exit (ExitCode(ExitSuccess))
import System.FilePath (combine, dropFileName, joinPath, takeFileName)
import System.IO (IOMode(ReadMode), hGetContents, openFile)
import System.Posix.Files (getSymbolicLinkStatus, isDirectory, isRegularFile)
import System.Process (readProcessWithExitCode)
 
filterSystemDirs :: [FilePath] -> [FilePath]
filterSystemDirs = filter (\f -> f /= "." && f /= "..")
 
data Entry = Copy FilePath -- source
           | Link FilePath -- resolved target
 
type EntryMap = Map FilePath (Maybe Entry)
 
parseLog :: EntryMap -> FilePath -> IO EntryMap
parseLog m f = do h <- openFile f ReadMode
                  c <- hGetContents h
                  return $ foldr (parse . words) m $ lines c
    where parse ["COPY", o, d] m' = insert m' d $ Copy o
          parse ["LINK", t, l] m' = insert m' l $ Link $
                                    combine (dropFileName l) t
          insert m f e = insertWith (const $ const Nothing) f (Just e) m
 
type FileMap = Map FilePath (Maybe FilePath)
 
resolve :: FilePath -> EntryMap -> FileMap
resolve srcDir em = foldWithKey resolve' empty em
    where resolve' kf Nothing fm = fm
          resolve' kf (Just (Copy f)) fm = insert fm kf f
          resolve' kf (Just (Link f)) fm =
              resolve' kf (join $ Data.Map.lookup f em) fm
          insert fm kf f = insertWith (const $ const Nothing) (takeFileName kf)
                           (Just $ combine srcDir f) fm
 
findBin :: FilePath -> IO [FilePath]
findBin = findBin' []
    where findBin' l f = do
            s <- getSymbolicLinkStatus f
            case (isDirectory s, isRegularFile s) of
              (True, _) -> do dirs <- getDirectoryContents f
                              let files = map (combine f) $
                                          filterSystemDirs dirs
                              foldM findBin' l files
              (_, True) -> isBinary f >>= return . choose (f : l) l
                               where choose a b c = if c then a else b
              _ -> return l
 
isBinary :: FilePath -> IO Bool
isBinary f = do (e, o, _) <-
                    readProcessWithExitCode "/usr/bin/file" ["-h", f] ""
                return $ e == ExitSuccess && (f ++ ": ELF ") `isPrefixOf` o
 
findSource :: FileMap -> FilePath -> Maybe FilePath
findSource m f = join $ Data.Map.lookup (takeFileName f) m
 
execute :: Integer -> (FilePath, Maybe FilePath) -> IO Integer
execute n (f, Nothing) = do putStrLn $ "No (unambiguous) source for " ++ f
                            return n
execute n (f, Just f') = do copyFile f' f
                            return $ n + 1
 
main :: IO ()
main = do [srcDir, logDir, instDir] <- getArgs
          dirs <- getDirectoryContents logDir
          let files = map (\x -> joinPath [logDir, x, "deliver.log"]) $
                      filterSystemDirs dirs
          files' <- filterM doesFileExist files
          em <- foldM parseLog empty files'
          bins <- findBin instDir
          n <- foldM execute 0
               (zip bins $ map (findSource $ resolve srcDir em) bins)
          putStrLn $
              show n ++ " file" ++ (if n == 1 then "" else "s") ++ " copied"

Just after system start up run

$ cd /sb-tree3 && valgrind --tool=callgrind --compress-strings=no /sb-tree1f/ooo-sb107/openoffice3/program/soffice.bin -swriter # press Ctrl-Q as soon as the text cursor starts to blink
$ cd /sb-tree3 && valgrind --tool=callgrind --compress-strings=no /sb-tree1f/ooo-sb107/openoffice3/program/soffice.bin -swriter # press Ctrl-Q as soon as the text cursor starts to blink
$ cd /sb-tree3 && valgrind --tool=callgrind --compress-strings=no /sb-tree1f/ooo-sb107/openoffice3/program/soffice.bin -swriter # press Ctrl-Q as soon as the text cursor starts to blink

to get one cold and two warm start-up (plus shut-down) measurements. The variance, even across cold and warm start ups, appears to be minimal.

Interesting first results, using grouping by ELF object in kcachegrind, are the instruction reads spent directly within the top scoring ELF objects:

ELF object absolute instruction reads relative instruction reads
total ∑ 2,597,556,857 100.00%
libuno_sal.so.3 731,982,997 28.18%
ld-2.7.so 551,561,186 21.23%
libpthread-2.7.so 259,698,813 10.00%
libstore.so.3 165,350,190 6.37%
configmgr2.uno.so 161,273,959 6.21%
libc-2.7.so 132,961,163 5.12%
libuno_cppu.so.3 111,161,292 4.28%
libfontconfig.so.1.3.0 91,777,652 3.53%
libuno_cppuhelpergcc3.so.3 43,931,839 1.69%
libtlli.so 43,326,910 1.67%
libgcc_s.so.1 25,236,175 0.97%
libfilterconfig1.so 23,319,326 0.90%

LD_DEBUG

Run

cd /sb-tree3
LD_DEBUG=bindings LD_DEBUG_OUTPUT=~/lddebug /sb-tree1/opt/openoffice.org3/program/soffice -swriter

and from the generated ~/lddebug.pid files pick the one corresponding to soffice.bin (usually the largest one). Pass it through the below Haskell script to dress it up. This gives information about all the symbolic relocations actually done at start-up (plus shut-down). Note that this includes all symbolic relocations from the data segments (as they cannot be postponed until needed).

-- Makefile:
--  .PHONY: lddebug-eval
--  lddebug-eval:
--   ghc-6.10.1 --make -o $@ Main.hs
--
-- For every dynamic object, list:
--  number of symbol bindings made by that object to itself
--  number of symbol bindings made by that object to other objects
--  number of symbol bindings made by that object (sum of above two)
--  number of symbol bindings made by other objects to that object
-- (Descending) sorting by any of those four columns is controlled by -1, -2,
-- -3, or -4, respectively.
-- Listing the symbols belonging to the different columns is controlled by +1,
-- +2, or +4, respectively.
--
-- $ LD_DEBUG=bindings LD_DEBUG_OUTPUT=lddebug soffice.bin && \
--    lddebug-eval -3 +1 +2 < lddebug > lddebug-a
 
{-# LANGUAGE ScopedTypeVariables #-}
 
module Main (main) where
 
import Control.Monad (when)
import Data.List (sort, sortBy)
import qualified Data.Map as M
import System.Environment (getArgs)
import Text.Regex.Posix ((=~))
 
main :: IO ()
main = do
  (so, lb) <- handleArgs
  c <- getContents
  let m = foldr process M.empty $ lines c
  reportTotal m
  mapM_ (report lb) $ sortObjs so $ M.toList m
 
newtype SortColumn = SortColumn Int
data ListBindings = ListBindings { listToSelf :: Bool, listToOther :: Bool,
                                   listFromOther :: Bool }
 
handleArgs :: IO (SortColumn, ListBindings)
handleArgs =
    return . foldl handleArg (SortColumn 0, ListBindings False False False)
        =<< getArgs
    where handleArg (_, lb) "-1" = (SortColumn 1, lb)
          handleArg (_, lb) "-2" = (SortColumn 2, lb)
          handleArg (_, lb) "-3" = (SortColumn 3, lb)
          handleArg (_, lb) "-4" = (SortColumn 4, lb)
          handleArg (so, ListBindings _ b2 b4) "+1" =
              (so, ListBindings True b2 b4)
          handleArg (so, ListBindings b1 _ b4) "+2" =
              (so, ListBindings b1 True b4)
          handleArg (so, ListBindings b1 b2 _) "+4" =
              (so, ListBindings b1 b2 True)
 
data Binding = Binding FilePath String deriving (Eq, Ord)
instance Show Binding where show (Binding fp sym) = fp ++ " " ++ sym
 
data Bindings = Bindings { toSelf :: [String], toOther :: [Binding],
                           fromOther :: [Binding] }
type Map = M.Map FilePath Bindings
 
process :: String -> Map -> Map
process l m =
    case l =~~~ "binding file ([^ ]+) (.* )?to ([^ :]+)( .*): .* `(.+)'" of
      [f1, _, f2, _, s] -> add f1 updateTo $
                           if f1 == f2 then m else add f2 updateFrom m
          where updateTo = if f1 == f2 then Bindings [s] [] []
                                       else Bindings [] [Binding f2 s] []
                updateFrom = Bindings [] [] [Binding f1 s]
                add = M.insertWith (+:+)
                Bindings x1 y1 z1 +:+ Bindings x2 y2 z2 =
                    Bindings (x1 +::+ x2) (y1 +::+ y2) (z1 +::+ z2)
                [] +::+ xs = xs
                [x] +::+ xs = x : xs
      _ -> m
 
reportTotal :: Map -> IO ()
reportTotal m = putStrLn $ "Total " ++ show s1 ++ " " ++ show s2 ++ " " ++
                show (s1 + s2) ++ " " ++ show s4
    where (s1, s2, s4) = M.fold sum (0, 0, 0) m
          sum (Bindings x y z) (a1, a2, a3) = (a1 + length x, a2 + length y,
                                               a3 + length z)
 
report :: ListBindings -> (FilePath, Bindings) -> IO ()
report lb (f, c) = do
    putStrLn $ f ++ " " ++ show (len toSelf) ++ " " ++ show (len toOther) ++
                 " " ++ show (len toSelf + len toOther) ++ " " ++
                 show (len fromOther)
    when (listToSelf lb) $ mapM_ (putStrLn . (" >< " ++)) $ sort $ toSelf c
    when (listToOther lb) $
         mapM_ (putStrLn . (" -> " ++) . show) $ sort $ toOther c
    when (listFromOther lb) $
         mapM_ (putStrLn . (" <- " ++) . show) $ sort $ fromOther c
    where len x = length $ x c
 
sortObjs :: SortColumn -> [(FilePath, Bindings)] -> [(FilePath, Bindings)]
sortObjs (SortColumn 0) = id
sortObjs (SortColumn 1) = sortBy (\(_, Bindings x _ _) (_, Bindings y _ _) -> compare (length y) (length x))
sortObjs (SortColumn 2) = sortBy (\(_, Bindings _ x _) (_, Bindings _ y _) ->
                                  compare (length y) (length x))
sortObjs (SortColumn 3) = sortBy (\(_, Bindings x1 x2 _) (_, Bindings y1 y2 _) ->
                                  compare (length y1 + length y2) (length x1 + length x2))
sortObjs (SortColumn 4) = sortBy (\(_, Bindings _ _ x) (_, Bindings _ _ y) ->
                                  compare (length y) (length x))
 
(=~~~) :: String -> String -> [String]
a =~~~ b = c
    where (_::String, _::String, _::String, c) = a =~ b

Note that ld-linux.so.2 on the used machine sometimes garbles lines of LD_DEBUG output (maybe a multi-threading issue), so the data produced by the above Haskell script need not be totally accurate.

Symbolic Linking

Issue 85679 “Link with -Wl,-Bsymbolic-functions -Wl,--dynamic-list-cpp-new -Wl,--dynamic-list-cpp-typeinfo when supported” suggest a performance boost on Linux through symbolic linking. This requires a fairly recent GNU ld. Experimenting with combining the existing (GCC 3.4.1 based) Hamburg unxlngi6.pro tool chain with (latest, as of March 2009) ld 2.19.1 failed, so I set up an environment using GNU binutils 2.19.1 and GNU GCC 4.3.3 (again, latest as of March 2009) on v20z-so3 (see above).

  • Build the new tool chain with ~/newgcc.sh ~/newgcc && rm -rf build, where ~/newgcc.sh is
#!/bin/bash
set -e
 
mkdir ${1?}
mkdir build
cd build
 
wget http://ftp.gnu.org/gnu/binutils/binutils-2.19.1.tar.bz2
tar xfj binutils-2.19.1.tar.bz2
mkdir binutils-build
(cd binutils-build; \
 ../binutils-2.19.1/configure --prefix=${1?}; \
 make; make install)
 
wget http://ftp.gnu.org/gnu/gmp/gmp-4.2.4.tar.bz2
tar xfj gmp-4.2.4.tar.bz2
 
wget http://www.mpfr.org/mpfr-2.4.1/mpfr-2.4.1.tar.bz2
tar xfj mpfr-2.4.1.tar.bz2
wget http://www.mpfr.org/mpfr-2.4.1/patches
(cd mpfr-2.4.1; patch -N -Z -p1 < ../patches)
 
wget http://ftp.gnu.org/gnu/gcc/gcc-4.3.3/gcc-4.3.3.tar.bz2
tar xfj gcc-4.3.3.tar.bz2
ln -s ../gmp-4.2.4 gcc-4.3.3/gmp
ln -s ../mpfr-2.4.1 gcc-4.3.3/mpfr
mkdir gcc-build
(cd gcc-build; \
 export PATH=${1?}${PATH+:$PATH}; \
 ../gcc-4.3.3/configure --prefix=${1?} --enable-languages=c,c++; \
 make; make install)
  • Again using CWS sb107 (see above), by now based on DEV300m42, replace the (Hamburg-internal) compiler-support libraries at $SRC_ROOT/so_prereq/baseline/unxlngi6 (libgcc_s.so.1, libstdc++.a, libstdc++.la, libstdc++.so.6.0.1) with the ones from the new tool chain (libgcc_s.so.1, libstdc++.a, libstdc++.la, libstdc++.so.6.0.10) and in $SRC_ROOT/solenv/bin/rpm-wrapper replace “${COMPATH?}” with “/so/env/gcc_3.4.1_p_linux_libc2.24”.
  • Merge in the relevant changes from Issue 85679 to support HAVE_LD_BSYMBOLIC_FUNCTIONS (ignoring the configure changes that are not relevant for a setsolar environment):
cd $SOURCE_ROOT/DEV300/ooo && svn merge --ignore-ancestry svn://svn.services.openoffice.org/ooo/cws/buildporting31b -r 264159:264162
  • Remove “SO:b_server” from $SRC_ROOT/top/prj/build.lst, to avoid an error later on when building (irrelevant, for OOo installation sets) $SRC_ROOT/soldep/bootstrp.
  • Unfortunately, I did not manage to combine the standard Hamburg build environment (setting a specific sysbaseroot) with the new toolchain, so had to go with a null sysbaseroot (i.e., using stuff directly from the v20z-so3 build machine). This means that results might be slightly different between the vanilla reference build and the builds checking the effects of symbolic linking.
  • I did three builds:
    • Build N using just the new tool chain (EXTERNAL_WARNINGS_NOT_ERRORS=TRUE is necessary as OOo is not yet completely warning-free for GCC 4.3.3):
SYSBASE_ROOT= setcws -pro sb107 -- -compath ~/newgcc -sysbaseroot
cd $SRC_ROOT/finalize && EXTERNAL_WARNINGS_NOT_ERRORS=TRUE build --all
    • Build S actually enabling symbolic linking:
SYSBASE_ROOT= setcws -pro sb107 -- -compath ~/newgcc -sysbaseroot
cd $SRC_ROOT/finalize && EXTERNAL_WARNINGS_NOT_ERRORS=TRUE HAVE_LD_BSYMBOLIC_FUNCTIONS=TRUE build --all
    • Build F using full symbolic linking (for functions and data) instead of symbolic linking for functions only, see issue 85679 additional comment 7. For that, I changed from “-Wl,-Bsymbolic-functions” to “-Wl,-Bsymbolic” in $SRC_ROOT/solenv/inc/unxlngi6.mk (and forgot to adapt $SRC_ROOT/icu/makefile.mk and $SRC_ROOT/stlport/makefile.mk accordingly, which, however, should only have a minor effect on the resulting numbers).
SYSBASE_ROOT= setcws -pro sb107 -- -compath ~/newgcc -sysbaseroot
cd $SRC_ROOT/finalize && EXTERNAL_WARNINGS_NOT_ERRORS=TRUE HAVE_LD_BSYMBOLIC_FUNCTIONS=TRUE build --all

This gave me four OOo installation sets (the original O one built with the standard Hamburg build environment, and the three new N, S, and F ones), which were measured on the dedicated machine (see above).

The time numbers (in each case, the average of three cold and six warm starts):

O N S F
cold real 11.16s 9.48s 10.53s 9.54s
user 2.09s 1.91s 1.71s 1.69s
sys 0.25s 0.24s 0.26s 0.26s
warm real 3.17s 3.02s 2.83s 2.70s
user 2.02s 1.68s 1.48s 1.41s
sys 0.16s 0.15s 0.14s 0.15s

Remarks:

  • The N cold-start real time looks somewhat too small (probably due to the overall small number of measurements taken).
  • The user times decrease as expected (as time spent in the run-time loader decreases).

The callgrind numbers (in each case, the second warm start in a row):

O N S F
2,283,122,716 100.00% 2,334,805,645 100.00% 2,038,552,787 100.00% 2,003,854,857 100.00%
sal 647,373,539 28.35% sal 691,393,484 29,61% sal 634,256,193 31.11% sal 634,307,373 31.65%
ld 553,872,166 24.26% ld 546,564,974 23.41% ld 305,756,844 15.00% ld 271,385,866 13.54%
pthread 201,802,573 8.84% pthread 201,363,821 8.62% pthread 204,557,648 10.03% pthread 204,573,303 10.21%
configmgr 161,661,066 7.08% configmgr 180,214,766 7.72% configmgr 180,278,175 8.84% configmgr 180,278,731 9.00%
c 121,552,893 5.32% c 111,557,687 4.78% c 109,967,449 5.39% c 109,791,414 5.48%
cppu 111,123,581 4.87% cppu 99,323,254 4.25% cppu 99,387,817 4.88% cppu 99,377,448 4.96%
fontconfig 62,609,949 2.74% fontconfig 62,704,639 2.69% fontconfig 62,592,873 3.07% fontconfig 62,423,589 3.12%
cppuhelper 43,994,951 1.93% store 56,053,961 2.40% store 56,053,990 2.75% store 56,053,990 2.80%
tl 43,389,333 1.90% cppuhelper 49,022,128 2.10% cppuhelper 49,146,109 2.41% cppuhelper 49,096,875 2.45%
store 39,787,117 1.74% tl 40,778,608 1.75% tl 40,778,745 2.00% tl 40,778,944 2.04%
comphelp 27,750,228 1.22% comphelp 25,798,266 1.10% comphelp 25,797,960 1.27% comphelp 25,797,960 1.29%
gcc_s 24,964,856 1.09% filterconfig 23,233,003 1.00% filterconfig 23,233,003 1.14% filterconfig 23,233,003 1.16%

Remarks:

  • callgrind-instrumented runs of the various OOo instances often terminated with unexpected C++ exceptions, see issue 100159 “unexpected exception from oooimprovement during shut down”. I could not get good runs for neither O nor N, so used ones crashing with com::sun::star::lang::DisposedException there; I did get good runs for both S and F, though. This probably makes the numbers for O and N somewhat different from what they would correctly be.
  • Overall numbers apparently dropped from DEV300m41 (see #callgrind above) to DEV300m42 (O), mostly in sal, store, and fontconfig.
  • The number of instruction reads appears to be generally higher for the new tool chain. This need not imply higher execution times, however. It might be caused by padding nops or choices of multiple simple (and in sum fast) instructions instead of fewer (and in sum slower) complex ones.
  • Numbers decreased significantly for gcc_s with the new tool chain. This is probably due to better support for C++ exception handling.
  • As expected, for ld numbers decreased significantly from N to S, and then yet some more from S to F (while numbers remained the same for all other objects).

The LD_DEBUG numbers:

Relocations O N S F
intra-object 45,698 44,480 16,520 11,623
inter-object 22,927 22,705 22,547 22,270
68,625 67,185 39,067 33,893

Remarks:

  • As expected, intra-object numbers go down while inter-object numbers stay almost the same.

Using -Bsymbolic is in general unsound, however (and thus variant F subtly broken). If an executable references data from a shared library, the instance of data used at runtime will not be the instance in the shared library memory but a copy residing in the executable memory (using R_386_COPY relocation to copy data from the shared library memory to the executable memory). This will obviously fail if the shared library “short circuits” to use its own instance. (It might work if all executables were built as PIC, but it appears too fragile and cumbersome to enforce this, especially for all the third-party code built as part of OOo.) Therefore, other mechanisms need to be sought to reduce the number of intra-object (and inter-object!) references past the S numbers.

DEV300m44

DEV300m44 unxlngi6.pro is now routinely built with a new tool chain in the Hamburg setsolar environment, using GNU binutils 2.19 and GCC 4.2.3, which is close to the tool chain I used above. Below are measurements for five unxlngi6.pro OOo versions:

  • B is the plain OOO300m9 (i.e., OOo 3.0.0) version built by Hamburg Release Engineering (using the old tool chain based on GCC 3.4.1), for reference.
  • O is the plain DEV300m44 version built by Hamburg Release Engineering, using GCC 4.2.3 and binutils 2.19.
  • C is a Hamburg setsolar-based build of CWS CWS sb107 with fixes for issue 85679, issue 99519, issue 100348, issue 100396, and issue 100576 (and some additional issues that are not performance relevant), also using GCC 4.2.3 and binutils 2.19. Especially issue 100576 “enable HAVE_LD_HASH_STYLE in sdev300.ini” seems to make a difference.
  • N is the same as C, but using my above tool chain (GCC 4.3.3 and binutils 2.19.1) instead—and again without the Hamburg SYSBASE_ROOT to be able to compile at all:
SYSBASE_ROOT= setcws -pro sb107 -- -compath ~/newgcc -sysbaseroot
cd $SRC_ROOT/finalize && EXTERNAL_WARNINGS_NOT_ERRORS=TRUE build --all
  • F is the same as N, only chainging CFLAGSOPT=-Os -fno-strict-aliasing to CFLAGSOPT=-O3 -fno-strict-aliasing in solenv/inc/unxlngi6.mk (and including a necessary fix for issue 100668 “explicit template instantiation: correct syntax”).

The time numbers (in each case, the average of three cold and six warm starts):

B O C C N F F F′′
cold real 10.39s 10.04s 8.29s 6.91s 8.54s 9.56s 7.63s 11.08s
user 2.03s 2.05s 1.59s 1.42s 1.53s 1.47s 1.19s 1.55s
sys 0.25s 0.26s 0.24s 0.27s 0.26s 0.28s 0.32s 0.31s
pgflts 542 548 549 241 550 607 241 1007
warm real 3.07s 3.23s 2.62s 3.15s 2.61s 2.40s 2.48s 2.45s
user 1.79s 1.87s 1.45s 1.46s 1.24s 1.16s 1.22s 1.22s
sys 0.15s 0.16s 0.16s 0.18s 0.18s 0.17s 0.19s 0.14s
pgflts 0 7 7 7 7 7 7 7
  • C′ and F′ are like C resp. F but with issue 100884 fixed and pagein-common and pagein-writer modified to contain all libraries from the OOo installation that are loaded during start-up.
  • F′′ is like F but with the call to pagein commented out in the soffice wrapper script.
  • “pgflts” is the number of “major (requiring I/O) page faults” as reported by /usr/bin/time -v.

The callgrind numbers:

B O C N F
2,343,921,428 100.00% 2,480,626,988 100.00% 2,154,221,636 100.00% 1,941,254,692 100.00% 1,784,892,501 100.00%
sal 613,760,471 26.19% sal 618,714,642 24.94% sal 618,363,619 28.70% sal 642,648,488 33.10% sal 583,727,656 32.70%
ld 520,524,128 22.21% ld 549,307,081 22.14% configmgr 267,645,553 12.42% ld 219,943,725 11.33% ld 219,918,343 12.32%
pthread 216,174,061 9.22% configmgr 267,677,829 10.79% ld 223,705,486 10.38% pthread 204,639,671 10.54% pthread 204,929,641 11.48%
configmgr 151,420,129 6.46% pthread 205,754,007 8.29% pthread 205,541,731 9.54% configmgr 180,332,775 9.29% configmgr 133,123,244 7.46%
c 136,653,675 5.83% c 115,297,223 4.65% c 115,251,998 5.35% c 110,134,686 5.67% c 110,172,575 6.17%
store 133,941,126 5.71% cppu 104,329,278 4.21% cppu 104,274,668 4.84% cppu 99,445,552 5.12% cppu 99,404,356 5.57%
cppu 101,645,154 4.34% cppuhelper 69,983,048 2.82% cppuhelper 69,869,741 3.24% fontconfig 62,572,767 3.22% fontconfig 62,470,938 3.50%
fontconfig 91,592,358 3.91% fontconfig 62,635,949 2.53% fontconfig 62,579,720 2.90% cppuhelper 49,302,429 2.54% tl 39,124,806 2.19%
tl 44,621,672 1.90% store 49,663,092 2.00% store 49,663,469 2.31% tl 40,230,939 2.07% cppuhelper 37,836,248 2.12%
cppuhelper 38,147,061 1.63% tl 46,338,109 1.87% tl 46,338,474 2.15% store 35,294,336 1.82% comphelp 28,243,242 1.58%
gcc_s 25,960,226 1.11% vcl 37,507,044 1.51% vcl 37,508,119 1.74% comphelp 25,799,196 1.33% store 27,574,934 1.54%
  • While the reductions from O to C are exactly as expected, the reductions from C to N seem over-optimistic (especially the extreme reduction for cofnigmgr). However, I could not find any mistakes (the set of dynamic libraries involved is exactly the same, high-level callgrind call numbers appear comparable). It appears that GCC 4.3.3 more aggressively inlines functions, which might explain some of the impact on C++ libraries that might contain lots of small functions (like configmgr or cppuhelper).

The LD_DEBUG numbers:

Relocations B O C N F
intra-object 44,088 45,226 15,110 14,793 14,790
inter-object 23,062 22,825 22,265 22,162 22,118
67,150 68,051 37,375 36,955 36,908
  • The reductions from C to N appear to be due to
    • inter-object resolutions of _ZTI and _ZTS (i.e., RTTI) symbols for types in anonymous namespaces being done directly rather than via symbol lookup;
    • inter- and intra-object resolutions of truly vague _ZTV (i.e., vtable) symbols (i.e., belonging to types without key functions, see Itanium C++ ABI) being done directly (i.e., always intra-object) rather than via symbol lookup;
    • to a small degree, calls to functions like memcpy being inlined instead of referring to libc.
Personal tools