Performance/Startup

From Apache OpenOffice Wiki
< Performance
Revision as of 14:14, 9 February 2009 by Sb (Talk | contribs)

(diff) ← Older revision | Latest revision (diff) | Newer revision → (diff)
Jump to: navigation, search

Issues

  • CWS sb103, integrated in OOO310_m1:
  • 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
Retrieved from "https://wiki.openoffice.org/w/index.php?title=Performance/Startup&oldid=111093"
Personal tools