Difference between revisions of "Performance/OOo31 LibrariesOnStartup"

From Apache OpenOffice Wiki
Jump to: navigation, search
(→‎Process Monitor results - OpenOffice.org data cold startup)
(→‎Process Monitor results - OpenOffice.org data cold startup)
Line 812: Line 812:
 
14:56:39,5302479 0.0000034 soffice.bin 2524 1220 IRP_MJ_CLOSE                             C:\Documents and Settings\Administrator\Application Data\URE\TYPES.RDB SUCCESS
 
14:56:39,5302479 0.0000034 soffice.bin 2524 1220 IRP_MJ_CLOSE                             C:\Documents and Settings\Administrator\Application Data\URE\TYPES.RDB SUCCESS
 
</source>
 
</source>
 +
 +
The following table shows what data files are accessed/read during startup. The times are currently summed up for the initial access. Many files are read on demand later during the startup process. The table provides two times for every entry as there are operations which are processed asynchronously, most often this is IRP_MJ_CREATE where IRP_MJ_READ is most of the time synchronously.
  
 
{| width="100%" border="1" cellpadding="2"
 
{| width="100%" border="1" cellpadding="2"

Revision as of 15:46, 16 February 2009

Performance analysis for OpenOffice.org 3.1 startup (Windows)

The startup performance of OpenOffice.org is not as good as many people expect. This has several reasons which more or less are based on the long development history. Due to discussion with many people it should be clear that we process too much code during the startup process.I think it's the best way to make the startup much faster if we completely understand what libraries are loaded and why they are used.

My first analysis results strengthen our thesis that too much code (libraries) is involved in the startup process. The following numbers have been retrieved from the build DEV300m40 under Windows. The Microsoft VisualStudio Debugger shows exactly when a library is loaded into the address space of a debugged process. Therefore it's valuable tool to retrieve information about the libraries which are loaded during startup.

Tools for Windows for performance analysis

Microsoft provides several tools to analyze performance problems. Especially for Windows Vista there are the Windows Performance Analysis Tools available for download. The Visual C++ 2008 Express suite provides a very good debugger. The famous and formerly known SysInternals tools are now maintained by Microsoft and can be downloaded here.

Overview about the system activities of OpenOffice.org during startup

The Process Monitor tools provides valuable insight into certain low-level system activities which are done by a process. Fortunately the tools is also able to make a summary of the system activities. This summary can be called a finger print as it shows the particularities of an application. All the startup times and analysis were done on the following machine:

The machine (a notebook) has the following attributes:

  • Intel Pentium M 1.80 GHz
  • 1GB RAM
  • Windows XP SP3
  • Toshiba MK6026GAX 60 GB, 2.5 Zoll - 5400rpm - UDMA100 - 16MB Cache

Although this is a fairly old notebook it matches very well a new kind of notebook class called Netbook. The CPU power should be a bit higher (out-of-order instead of in-order-CPU and 200 Mhz more speed) but the other attributes fit well.

Cold startup

The cold startup time for OpenOffice.org DEV300m40 on this machine:

  • ~14 seconds (Splash screen visible)
  • ~22 seconds (Start Center ready )
  • ~34 seconds (Writer up and running)

OpenOffice.org DEV300m40 System Activities.png

Process Monitor summary data:

System activity Number
File Events 26.146
Registry Events 2.364
Network Events 0
Max. CPU utilization 32% total / 21% kernel

What can be see from the summary?

  • On cold start OpenOffice.org is clearly I/O and not CPU bound. Even on this slow system the CPU power is only fractionaly used.

Warm startup

The warm startup time for OpenOffice.org DEV300m40 on this machine:

  • ~1 seconds (Splash screen visible)
  • ~2 seconds (Start Center ready )
  • ~4 seconds (Writer up and running)

OpenOffice.org DEV300m40 System Activities WarmStartup.PNG

System activity Number
File Events 22.547
Registry Events 2.284
Network Events 0
Max. CPU utilization 78% total / 38% kernel
  • On warm start OpenOffice.org is much more balanced between file I/O and CPU.

OpenOffice.org libraries

Some statistic data about the OpenOffice.org libraries

This data is based on the DEV300m40 build, Windows, wntmsci12.pro.

Data/Folder Program Basis URE Sum
Number 4 293 50 347
Size (Bytes) 2.750.464 161.765.640 6.677.152 171.193.256

I use certain measurement points to see what libraries have been loaded by OpenOffice.org:

Measurement point Total number of libraries loaded (OOo libs) Percentage of all OpenOffice.org libraries. Percentage of all OpenOffice.org libraries (size)
Desktop ctor (Application object created on the stack) 57 (33) 9,50 % 26,14 %
Desktop::Init (First initializations, e.g. UNO service manager) 59 (34) 9,80 % 26,18 %
Desktop::Main () just entered 70 (34) 13,00 % 27,59 %
Desktop::Main (before we enter the main message loop)/StartCenter ready 98 (70) 20,20 % 34,16 %
Empty Writer document 129 (93) 26,80 % 46,37 %

Table with the loading order of libraries of OpenOffice.org under Windows

The following table shows when&what libraries are loaded during the OpenOffice.org 3.1 startup.

Order of Loading Library/Executable Size
001 soffice.bin 7.418.368
002 sal3.dll 1.732.608
003 uwinapi.dll 86.016
004 sofficeapi.dll 326.144
005 comphelp4MSC.dll 948.224
006 cppuhelper3MSC.dll 431.104
007 salhelper3MSC.dll 13.824
008 cppu3.dll 143.360
009 stlport_vc7145.dll 597.504
010 ucbhelper4MSC.dll 356.864
011 vos3MSC.dll 94.208
012 i18nisolang1MSC.dll 24.576
013 sfxmi.dll 3.110.912
014 fwemi.dll 849.408
015 fwimi.dll 299.008
016 utlmi.dll 465.920
017 tlmi.dll 509.952
018 basegfxmi.dll 572.928
019 vclmi.dll 3.074.048
020 sotmi.dll 257.024
021 i18nutilMSC.dll 67.072
022 icuuc40.dll 949.760
023 icudt40.dll 13.912.064
024 svlmi.dll 724.992
025 svtmi.dll 2.884.608
026 tkmi.dll 1.870.336
027 jvmfwk3.dll 89.088
028 libxml2.dll 970.752
029 sbmi.dll 1.310.208
030 xcrmi.dll 529.920
031 saxmi.dll 80.384
032 jmi_g.dll 32.768
033 jvmaccess3MSC.dll 25.600
Desktop ctor 44.759.552
034 msci_uno.dll 52.224
Desktop::Init() just entered the method 44.811.776
035 bootstrap.dll 453.632
036 reg3.dll 99.328
037 store3.dll 78.336
038 unsafe_uno_uno.dll 12.800
039 purpenvhelper3MSC.dll 18.432
040 configmgr2.uno.dll 1.432.064
041 stocservices.uno.dll 92.672
042 sysmgr1.dll 37.888
043 sax.uno.dll 135.680
044 localebe1.uno.dll 30.208
045 behelper.uno.dll 31.232
Desktop::Main() just entered the method 47.234.048
046 splmi.dll 148.992
047 ucb1.dll 197.632
048 fwlmi.dll 106.496
049 ucpfile1.dll 245.248
050 fwkmi.dll 1.879.552
051 dnd.dll 115.200
052 fileacc.dll 52.224
053 package2.dll 248.320
054 fsstorage.uno.dll 94.208
055 i18npool.dll 1.235.456
056 icuin40.dll 1.052.160
057 updchk.uno.dll 166.912
058 libcurl.dll 121.344
059 deploymentmi.uno.dll 266.240
060 deploymentmiscmi.dll 100.864
061 libdb42.dll 541.184
062 helplinkermi.dll 134.144
063 libxslt.dll 166.400
064 updatefeed.uno.dll 77.824
065 unoxmlmi.dll 280.064
066 ucpexpand1.uno.dll 24.576
067 updchkmi.dll 48.640
068 resmi.dll 65.024
069 lngmi.dll 982.016
070 xomi.dll 2.898.432
Desktop::Main() just before entering the message loop 58.483.200
071 oleautobridge.uno.dll 280.576
072 emsermi.dll 148.992
073 uuimi.dll 198.144
074 filterconfig1.dll 188.416
075 swmi.dll 7.332.352
076 svxmi.dll 9.172.992
077 avmediami.dll 56.832
078 gomi.dll 295.936
079 drawinglayermi.dll 802.304
080 canvastoolsmi.dll 498.176
081 aggmi.dll 129.024
082 cppcanvasmi.dll 285.184
083 localedata_euro.dll 642.048
084 localedata_en.dll 104.448
085 xstor.dll 239.616
086 reflection.uno.dll 99.840
087 guesslangmi.dll 36.864
088 libtextcat.dll 14.848
089 introspection.uno.dll 98.816
090 sysdtrans.dll 107.008
091 ftrans1.dll 50.688
092 mcnttype.dll 33.792
093 ldapbe2.uno.dll 83.968
Empty Writer document up and running 79.384.014

Just to get an idea what the first measurement point "Desktop ctor" means. The following code snippet can be found in the desktop project 

extern "C" int soffice_main()
{
    tools::extendApplicationEnvironment();
 
    RTL_LOGFILE_PRODUCT_TRACE( "PERFORMANCE - enter Main()" );
 
    desktop::Desktop aDesktop; // FIRST MEASUREMENT POINT
    // This string is used during initialization of the Gtk+ VCL module
    aDesktop.SetAppName( rtl::OUString(RTL_CONSTASCII_USTRINGPARAM("soffice")) );
    SVMain();
 
    return 0;
}

It's obvious to see that several libraries are loaded/used that nobody would think of. Especially sbmi.dll (Basic), sfx2mi.dll (old framework), sotmi.dll are loaded before any initialization is done, even VCL is not inialized yet. There are several other libraries where one can ask why they are used that early in the startup process. This simple analysis already raised many questions that need to be answered.

Table with the loading order of libraries of svdem.exe under Windows

In contrast to the OpenOffice.org executable the following table provides the libraries used by the svdem.exe which is a minimal VCL based application (built in the VCL project).

Order of Loading Library/Executable Size
001 svdem.exe 15360
002 cppuhelper3MSC.dll 431.104
003 sal3.dll 1.732.608
004 uwinapi.dll 86.016
005 salhelper3MSC.dll 13.824
006 cppu3.dll 143.360
007 stlport_vc7145.dll 597.504
008 tlmi.dll 509.952
009 vos3MSC.dll 94.208
010 basegfxmi.dll 572.928
011 iso18nisolangMSC.dll 24.576
012 comphelp4MSC.dll 948.224
013 ucbhelper4MSC.dll 356.864
014 vclmi.dll 3.074.048
015 sotmi.dll 257.024
016 utlmi.dll 465.920
017 i18nutilMSC.dll 67072
018 icuuc40.dll 949760
019 icudt40.dll 13912064
SAL_IMPLEMENT_MAIN() entered 24.252.416
020 bootstrap.dll 453.632
021 reg3.dll 99.328
022 store3.dll 78.336
023 msci_uno.dll 52.224
024 unsafe_uno_uno.dll 12.800
025 purpenvhelper3MSC.dll 18.432
026 tkmi.dll 1.870.336
Application usable 26.837.504

The following code snippet from svdem.cxx (inside in VCL/workben) shows where the first measurement point is located. 

SAL_IMPLEMENT_MAIN()
{
    tools::extendApplicationEnvironment(); // <- First measurement point
 
    Reference< XMultiServiceFactory > xMS;
    xMS = cppu::createRegistryServiceFactory( rtl::OUString( RTL_CONSTASCII_USTRINGPARAM( "applicat.rdb" ) ), sal_True );
 
    InitVCL( xMS );
    ::Main();
    DeInitVCL();
 
    return 0;
}

Even the svdem.exe needs to load many OpenOffice.org libraries. This result supports people who report that also svdem.exe has a bad cold startup time. There is one library (icudt40.dll) which has a size that makes up about 50% of the sum of all libraries.

Measurement point Total number of libraries loaded (OOo libs) Percentage of all OpenOffice.org libraries. Percentage of all OpenOffice.org libraries (size)
SAL_IMPLEMENT_MAIN() entered 44 (19) 5,47 % 14,16%
svdem.exe up and running 60 (26) 7,95 % 15,68 %

File I/O during OpenOffice.org startup

It was reported that OpenOffice.org has a high amount of file access during startup. This part wants to analyze what file I/O is done by OpenOffice.org. Under Windows one can use the Microsoft tools from www.sysinternals.com who provides Process Monitor (FileMon is replaced by Process Monitor). Process Monitor provides many more information, especially durations for system calls with a very high timer resolution, than FileMon and therefore is a better tools for our purpose.

Costs of library loading

This chapter tries to figure out what costs are involved in library loading under Windows. As described in the previous chapters OpenOffice.org uses a big number of libraries during startup. Currently it's not really known what does this cost, especially in the cold startup scenario where no libraries could be loaded from the cache.

Process Monitor results - OpenOffice.org cold startup

This snippet below has been directly copied from the output of Process Monitor and shows how the sal3.dll library is opened in OpenOffice.org during startup. This OpenOffice.org startup was done after a reboot of the machine where one can expect that no application libraries are found in the system cache. I did this test with a much slower machine (see machine details above) to better see the impact of file I/O.

The cold startup time is fairly good reproducable as long as Windows XP doesn't create a prefetch file for the application (normally located inside %systemroot%\prefetch). The Process Monitor output will also dramatically change when Windows starts to prefetch. You can find more information about this Microsoft Windows feature here. 

Time (hh:mm:ss)  Dur. (s)   Executable    PID   TID  Function                   Path/File/Name                                              Result         Parameters
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
11:16:07,6025666 0.0000134  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\program\sal3.dll	    NAME NOT FOUND	
11:16:07,6027267 0.0000162  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\WINDOWS\system32\sal3.dll	                            NAME NOT FOUND	
11:16:07,6028767 0.0000087  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\WINDOWS\system\sal3.dll	                            NAME NOT FOUND	
11:16:07,6029854 0.0000128  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\WINDOWS\sal3.dll	                                    NAME NOT FOUND	
11:16:07,6031072 0.0000100  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\program\sal3.dll	    NAME NOT FOUND	
11:16:07,6436763 0.0000198  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll    NAME NOT FOUND	
11:16:07,6738153 0.0007130  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   AllocationSize: 1.732.608, EndOfFile: 1.732.608, FileAttributes: A
11:16:07,6746442 0.0000126  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\program\sal3.dll	    NAME NOT FOUND	
11:16:07,6747895 0.0000153  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\WINDOWS\system32\sal3.dll	                            NAME NOT FOUND	
11:16:07,6749412 0.0000089  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\WINDOWS\system\sal3.dll	                            NAME NOT FOUND	
11:16:07,6750510 0.0000122  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\WINDOWS\sal3.dll	                                    NAME NOT FOUND	
11:16:07,6751677 0.0000101  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\program\sal3.dll	    NAME NOT FOUND	
11:16:07,6755242 0.0000126  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll    NAME NOT FOUND	
11:16:07,6756639 0.0000067  soffice.bin	 3904  3908  FASTIO_NETWORK_QUERY_OPEN  C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   AllocationSize: 1.732.608, EndOfFile: 1.732.608, FileAttributes: A
11:16:07,6757971 0.1243334  soffice.bin	 3904  3908  IRP_MJ_CREATE              C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Desired Access: Execute/Traverse, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened
11:16:07,6758737 0.0212516  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 0, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7227570 0.0003288  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.728.512, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7230998 0.0004252  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.716.224, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7235563 0.0002313  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.724.416, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7240611 0.0002020  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.703.936, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7242740 0.0140059  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.720.320, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7383006 0.0005361  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.708.032, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7579252 0.0158132  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.679.360, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7738479 0.0001095  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.683.456, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7741284 0.0010766  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.712.128, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7752335 0.0005350  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.691.648, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7929455 0.0004247  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.671.168, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,7934040 0.0004101  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.675.264, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,8000587 0.0000143  soffice.bin	 3904  3908  IRP_MJ_CREATE	        C:\Program Files\OpenOffice.org 3\program	            SUCCESS	   Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:16:07,8000814 0.0000120  soffice.bin	 3904  3908  IRP_MJ_DIRECTORY_CONTROL   C:\Program Files\OpenOffice.org 3\program\soffice.bin       SUCCESS	   Filter: soffice.bin, 1: soffice.bin
11:16:07,8001043 0.0000044  soffice.bin	 3904  3908  IRP_MJ_CLEANUP             C:\Program Files\OpenOffice.org 3\program	            SUCCESS	
11:16:07,8006798 0.0000028  soffice.bin	 3904  3908  FASTIO_QUERY_INFORMATION   C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   AllocationSize: 1.732.608, EndOfFile: 1.732.608, NumberOfLinks: 1, DeletePending: False, Directory: False
11:16:07,8008901 0.0000053  soffice.bin	 3904  3908  IRP_MJ_CLEANUP             C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	
11:16:07,8012776 0.0000000  soffice.bin	 3904  3908  Load Image	                C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Image Base: 0x60100000, Image Size: 0x1ae000
11:16:07,8013036 0.0004350  soffice.bin	 3904  3908  IRP_MJ_READ                C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.711.104, Length: 1.536, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,8032435 0.0000534  soffice.bin	 3904  3908  IRP_MJ_CREATE	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll.2.Manifest NAME NOT FOUND Desired Access: Generic Read/Execute, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, AllocationSize: n/a
11:16:07,8035125 0.0006993  soffice.bin	 3904  3908  IRP_MJ_CREATE	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll.2.Config NAME NOT FOUND Desired Access: Generic Read/Execute, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, AllocationSize: n/a
11:16:07,8286051 0.0006755  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 1.679.360, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
11:16:07,8292932 0.0003053  soffice.bin	 3904  3908  IRP_MJ_READ	        C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	    SUCCESS	   Offset: 172.032, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O

If you look at the output from Process Monitor one can stumble that the time stamp of the next function doesn't match or overlaps the previous one + duration. Some functions are processed asynchronously and Process Monitor always logs the duration of a function when the result is available. The output from Process Monitor shows us that libraries are not read in one portion into the address space of a process. There are three different access phases one can see here and which can also be found when looking at other application libraries.

  • The first page (4096 bytes) of the library is loaded. This is completely clear as the loader needs to look at the PE header of the library.
  • Different parts of the library are loaded which always have the same size (4096 bytes) which also the normal page size of x86 based CPUs.
  • At the end data is read with different sizes (e.g. sal3 with 1.536, 16.384 and 16.384 bytes)

It's interesting to see that the sum of durations for the initial part of sal3 needs ~183ms where total elapsed time is ~226ms. So most of the time was used for file operations. It's obvious that more parts of the libraries are loaded into memory whenever more code/data is needed. Therefore it should be clear that the numbers are more the lower bound for library loading. About 180 ms sounds not very much but if we look at the number of libraries we load at startup this can grow to huge times!

The following table tries to show what time is initially spent for all libraries that are loaded during startup. It will help us to see what impact library loading has on cold startup time. If you look at the times you will clearly see that it's not always related to the library size, there must be other parameters which influence it. May be it depends on the number of exports or statics. This must be clarified to know what can we do to improve here.

See Performance/Startup#ELF_Dynamic_Objects; Sb 15:14, 11 February 2009 (UTC).

Relocations can definitely have an impact but this shouldn't happen for OpenOffice.org as we rebase our libraries. That means that all application libraries are set with an initial load address which doesn't overlap. All relocations inside the library are overwritten to match this load address. If Windows is able to load the library exactly at this load address nothing must be done, otherwise relocations are necessary.

See [MSDN magazin - Optimizing DLL Load Time Performance]
Order of Loading Library/Executable Size Time (ms) to init/load (Process Monitor)
001 soffice.bin 7.418.368 691
002 sal3.dll 1.732.608 183
003 uwinapi.dll 86.016 72
004 sofficeapi.dll 326.144 168
005 comphelp4MSC.dll 948.224 361
006 cppuhelper3MSC.dll 431.104 364
007 salhelper3MSC.dll 13.824 56
008 cppu3.dll 143.360 139
009 stlport_vc7145.dll 597.504 253
010 ucbhelper4MSC.dll 356.864 153
011 vos3MSC.dll 94.208 56
012 i18nisolang1MSC.dll 24.576 95
013 sfxmi.dll 3.110.912 492
014 fwemi.dll 849.408 170
015 fwimi.dll 299.008 103
016 utlmi.dll 465.920 234
017 tlmi.dll 509.952 190
018 basegfxmi.dll 572.928 234
019 vclmi.dll 3.074.048 300
020 sotmi.dll 257.024 100
021 i18nutilMSC.dll 67.072 49
022 icuuc40.dll 949.760 194
023 icudt40.dll 13.912.064 70
024 svlmi.dll 724.992 172
025 svtmi.dll 2.884.608 473
026 tkmi.dll 1.870.336 322
027 jvmfwk3.dll 89.088 65
028 libxml2.dll 970.752 215
029 sbmi.dll 1.310.208 712
030 xcrmi.dll 529.920 151
031 saxmi.dll 80.384 47
032 jmi_g.dll 32.768 22
033 jvmaccess3MSC.dll 25.600 45
Desktop ctor 44.759.552 5168ms elapsed / >6951ms libs i/o time
034 msci_uno.dll 52.224 70
Desktop::Init() just entered the method 44.811.776 7967ms elapsed / >7021ms libs i/o time
035 bootstrap.dll 453.632 121
036 reg3.dll 99.328 84
037 store3.dll 78.336 57
038 unsafe_uno_uno.dll 12.800 45
039 purpenvhelper3MSC.dll 18.432 62
040 configmgr2.uno.dll 1.432.064 219
041 stocservices.uno.dll 92.672 87
042 sysmgr1.dll 37.888 68
043 sax.uno.dll 135.680 101
044 localebe1.uno.dll 30.208 85
045 behelper.uno.dll 31.232 63
Desktop::Main() just entered the method 47.234.048 12214ms elapsed / >8013ms libs i/o time
046 splmi.dll 148.992 100
047 ucb1.dll 197.632 65
048 fwlmi.dll 106.496 84
049 ucpfile1.dll 245.248 121
050 fwkmi.dll 1.879.552 265
051 dnd.dll 115.200 54
052 fileacc.dll 52.224 35
053 package2.dll 248.320 114
054 fsstorage.uno.dll 94.208 81
055 i18npool.dll 1.235.456 236
056 icuin40.dll 1.052.160 227
057 updchk.uno.dll 166.912 82
058 libcurl.dll 121.344 38
059 deploymentmi.uno.dll 266.240 156
060 deploymentmiscmi.dll 100.864 86
061 libdb42.dll 541.184 111
062 helplinkermi.dll 134.144 40
063 libxslt.dll 166.400 90
064 updatefeed.uno.dll 77.824 8
065 unoxmlmi.dll 280.064 144
066 ucpexpand1.uno.dll 24.576 37
067 updchkmi.dll 48.640 58
068 resmi.dll 65.024 88
069 lngmi.dll 982.016 210
070 xomi.dll 2.898.432 331
Desktop::Main() just before entering the message loop 58.483.200 22088ms elapsed / >10825ms libs i/o time
071 oleautobridge.uno.dll 280.576 134
072 emsermi.dll 148.992 83
073 uuimi.dll 198.144 90
074 filterconfig1.dll 188.416 89
075 swmi.dll 7.332.352 543
076 svxmi.dll 9.172.992 556
077 avmediami.dll 56.832 133
078 gomi.dll 295.936 166
079 drawinglayermi.dll 802.304 199
080 canvastoolsmi.dll 498.176 201
081 aggmi.dll 129.024 116
082 cppcanvasmi.dll 285.184 146
083 localedata_euro.dll 642.048 184
084 localedata_en.dll 104.448 71
085 xstor.dll 239.616 111
086 reflection.uno.dll 99.840 88
087 guesslangmi.dll 36.864 45
088 libtextcat.dll 14.848 59
089 introspection.uno.dll 98.816 86
090 sysdtrans.dll 107.008 55
091 ftrans1.dll 50.688 63
092 mcnttype.dll 33.792 44
093 ldapbe2.uno.dll 83.968 47
Empty Writer document up and running 79.384.014 33120ms elapsed / >14183ms libs i/o time

Process Monitor results - OpenOffice.org warm startup

Process Monitor output copied initial loading/reading of sal3.dll. 

Time (hh:mm:ss)  Dur. (s)   Executable    PID   TID  Function                   Argument (Path/File/Name)                                Result
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
15:42:59,9788505 0.0000145  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\program\sal3.dll	         NAME NOT FOUND	
15:42:59,9789974 0.0000165  soffice.bin	 3108	2348	QueryOpen	C:\WINDOWS\system32\sal3.dll	                                 NAME NOT FOUND	
15:42:59,9792078 0.0000095  soffice.bin	 3108	2348	QueryOpen	C:\WINDOWS\system\sal3.dll	                                 NAME NOT FOUND	
15:42:59,9793142 0.0000131  soffice.bin	 3108	2348	QueryOpen	C:\WINDOWS\sal3.dll	                                         NAME NOT FOUND	
15:42:59,9794293 0.0000098  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\program\sal3.dll	         NAME NOT FOUND	
15:42:59,9795715 0.0000148  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll	 NAME NOT FOUND	
15:42:59,9797148 0.0000090  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	         SUCCESS	AllocationSize: 1.732.608, EndOfFile: 1.732.608, FileAttributes: A
15:42:59,9798246 0.0000098  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\program\sal3.dll	         NAME NOT FOUND	
15:42:59,9799727 0.0000123  soffice.bin	 3108	2348	QueryOpen	C:\WINDOWS\system32\sal3.dll	                                 NAME NOT FOUND	
15:42:59,9801045 0.0000087  soffice.bin	 3108	2348	QueryOpen	C:\WINDOWS\system\sal3.dll	                                 NAME NOT FOUND	
15:42:59,9802048 0.0000104  soffice.bin	 3108	2348	QueryOpen	C:\WINDOWS\sal3.dll	                                         NAME NOT FOUND	
15:42:59,9803093 0.0000090  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\program\sal3.dll	         NAME NOT FOUND	
15:42:59,9804412 0.0000117  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll	 NAME NOT FOUND	
15:42:59,9805814 0.0000067  soffice.bin	 3108	2348	QueryOpen	C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	         SUCCESS	AllocationSize: 1.732.608, EndOfFile: 1.732.608, FileAttributes: A
15:42:59,9807110 0.0002995  soffice.bin	 3108	2348	CreateFile	C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	         SUCCESS	Desired Access: Execute/Traverse, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened
15:42:59,9808652 0.0000132  soffice.bin	 3108	2348	CreateFile	C:\Program Files\OpenOffice.org 3\program	                 SUCCESS	Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
15:42:59,9808870 0.0000095  soffice.bin	 3108	2348	QueryDirectory	C:\Program Files\OpenOffice.org 3\program\soffice.bin	         SUCCESS	Filter: soffice.bin, 1: soffice.bin
15:42:59,9809840 0.0000050  soffice.bin	 3108	2348	CloseFile	C:\Program Files\OpenOffice.org 3\program	                 SUCCESS	
15:42:59,9811893 0.0000056  soffice.bin	 3108	2348	CloseFile	C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	         SUCCESS	
15:42:59,9815449 0.0000000  soffice.bin	 3108	2348	Load Image	C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll	         SUCCESS	Image Base: 0x60100000, Image Size: 0x1ae000
15:42:59,9817950 0.0000561  soffice.bin	 3108	2348	CreateFile	C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll.2.Manifest	 NAME NOT FOUND	Desired Access: Generic Read/Execute, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, AllocationSize: n/a
15:42:59,9828853 0.0000503  soffice.bin	 3108	2348	CreateFile	C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll.2.Config	 NAME NOT FOUND	Desired Access: Generic Read/Execute, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, AllocationSize: n/a

The warm start scenario shows us that there are no read operations in the log. Windows is able to map the code/data of the library into the process without any READ operation. The total time consumed for these operations is very slim. Total duration time is ~0.6ms and the elapsed time ~4ms.

Costs of data file access

Process Monitor results - OpenOffice.org data cold startup

The following parts wants to get information how much time is used to read/write from/to data files during startup.

Log output copied from Process Monitor initial reading a typical ini configuration file (soffice.ini). 

Time (hh:mm:ss)  Dur. (s)  Executable    PID  TID Function                 Path/File/Name                                        Result      Parameter
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
14:56:38,5637743 0.0000097 soffice.bin	2524 1220 IRP_MJ_DIRECTORY_CONTROL C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Type: QueryDirectory, Filter: soffice.ini, 2: soffice.ini
14:56:38,5637966 0.0000048 soffice.bin	2524 1220 IRP_MJ_CLEANUP	   C:\Program Files\OpenOffice.org 3\program	         SUCCESS
14:56:38,5638078 0.0000047 soffice.bin	2524 1220 IRP_MJ_CLOSE	           C:\Program Files\OpenOffice.org 3\program	         SUCCESS
14:56:38,5639304 0.0120725 soffice.bin	2524 1220 IRP_MJ_CREATE	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened
14:56:38,5639888 0.0109416 soffice.bin	2524 1220 IRP_MJ_READ	           C:\$Mft	                                         SUCCESS     Offset: 82.997.248, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:38,5750276 0.0000062 soffice.bin	2524 1220 IRP_MJ_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 0, Length: 177, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:38,5751358 0.0000069 System	   4   52 IRP_MJ_QUERY_INFORMATION C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Type: QueryNameInformationFile, Name: \Program Files\OpenOffice.org 3\progra\soffice.ini
14:56:38,5759292 0.0000153 soffice.bin	2524 1220 IRP_MJ_CREATE	           C:\Program Files\OpenOffice.org 3\program	         SUCCESS     Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
14:56:38,5759535 0.0000103 soffice.bin	2524 1220 IRP_MJ_DIRECTORY_CONTROL C:\Program Files\OpenOffice.org 3\program\soffice.bin SUCCESS     Type: QueryDirectory, Filter: soffice.bin, 2: soffice.bin
14:56:38,5759752 0.0000048 soffice.bin	2524 1220 IRP_MJ_CLEANUP	   C:\Program Files\OpenOffice.org 3\program	         SUCCESS
14:56:38,5759861 0.0000051 soffice.bin	2524 1220 IRP_MJ_CLOSE	           C:\Program Files\OpenOffice.org 3\program	         SUCCESS
14:56:38,5760205 0.0000053 soffice.bin	2524 1220 IRP_MJ_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 0, Length: 79
14:56:38,5760392 0.0000034 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 13, Length: 79
14:56:38,5760540 0.0000025 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 21, Length: 79
14:56:38,5760658 0.0000022 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 48, Length: 79
14:56:38,5760764 0.0000022 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 79, Length: 79
14:56:38,5760867 0.0000025 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 104, Length: 73
14:56:38,5760970 0.0000023 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 124, Length: 53
14:56:38,5761077 0.0000025 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS     Offset: 165, Length: 12
14:56:38,5761180 0.0000022 soffice.bin	2524 1220 FASTIO_READ	           C:\Program Files\OpenOffice.org 3\program\soffice.ini END OF FILE Offset: 177, Length: 79
14:56:38,5761325 0.0000053 soffice.bin	2524 1220 IRP_MJ_CLEANUP	   C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS
14:56:38,5761473 0.0000048 soffice.bin	2524 1220 IRP_MJ_CLOSE	           C:\Program Files\OpenOffice.org 3\program\soffice.ini SUCCESS

Log output copied from Process Monitor initial reading a typical rdb file (types.rdb). 

Time (hh:mm:ss)  Dur. (s)  Executable   PID  TID Function                                   Path/File/Name                                                         Result         Parameter
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
14:56:39,4514941 0.0548036 soffice.bin 2524 1220 IRP_MJ_CREATE	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Random Access, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened
14:56:39,4515390 0.0001501 soffice.bin 2524 1220 IRP_MJ_READ	                            C:\$Mft	                                                           SUCCESS	  Offset: 36.536.320, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,4517690 0.0152078 soffice.bin 2524 1220 IRP_MJ_READ	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Offset: 0, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,4670902 0.0000075 System	  4   52 IRP_MJ_QUERY_INFORMATION                   C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Type: QueryNameInformationFile, Name: \Program Files\OpenOffice.org 3\URE\misc\types.rdb
14:56:39,4671195 0.0214030 System	  4   24 IRP_MJ_READ	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Offset: 4.096, Length: 65.536, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,4671894 0.0367242 soffice.bin 2524 1220 IRP_MJ_READ	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Offset: 847.872, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,5039792 0.0009448 soffice.bin 2524 1220 IRP_MJ_READ	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Offset: 843.776, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,5049374 0.0003269 soffice.bin 2524 1220 IRP_MJ_READ	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Offset: 839.680, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,5062172 0.0000179 soffice.bin 2524 1220 IRP_MJ_CREATE	                            C:\Program Files\OpenOffice.org 3\program	                           SUCCESS	  Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
14:56:39,5062449 0.0000123 soffice.bin 2524 1220 IRP_MJ_DIRECTORY_CONTROL                   C:\Program Files\OpenOffice.org 3\program\soffice.bin                  SUCCESS	  Type: QueryDirectory, Filter: soffice.bin, 2: soffice.bin
14:56:39,5062683 0.0000048 soffice.bin 2524 1220 IRP_MJ_CLEANUP	                            C:\Program Files\OpenOffice.org 3\program	                           SUCCESS
14:56:39,5062792 0.0000053 soffice.bin 2524 1220 IRP_MJ_CLOSE	                            C:\Program Files\OpenOffice.org 3\program	                           SUCCESS
14:56:39,5063203 0.0000039 soffice.bin 2524 1220 FASTIO_ACQUIRE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  SyncType: SyncTypeCreateSection, PageProtection: PAGE_READONLY
14:56:39,5063290 0.0000036 soffice.bin 2524 1220 FASTIO_QUERY_INFORMATION	            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Type: QueryStandardInformationFile, AllocationSize: 851.968, EndOfFile: 851.968, NumberOfLinks: 1, DeletePending: False, Directory: False
14:56:39,5063371 0.0000022 soffice.bin 2524 1220 FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS
14:56:39,5063443 0.0000020 soffice.bin 2524 1220 FASTIO_ACQUIRE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS        SyncType: SyncTypeOther
14:56:39,5063505 0.0000019 soffice.bin 2524 1220 FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS
14:56:39,5063594 0.0000025 soffice.bin 2524 1220 FASTIO_QUERY_INFORMATION	            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Type: QueryStandardInformationFile, AllocationSize: 851.968, EndOfFile: 851.968, NumberOfLinks: 1, DeletePending: False, Directory: False
14:56:39,5064477 0.0113389 soffice.bin 2524 1220 IRP_MJ_READ	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Offset: 450.560, Length: 32.768, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,5178408 0.0122350 soffice.bin 2524 1220 IRP_MJ_READ	                            C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb                   SUCCESS	  Offset: 155.648, Length: 32.768, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
14:56:39,5302094 0.0000603 soffice.bin 2524 1220 IRP_MJ_CREATE	                            C:\Documents and Settings\Administrator\Application Data\URE\types.rdb PATH NOT FOUND Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Random Access, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a
14:56:39,5302479 0.0000034 soffice.bin 2524 1220 IRP_MJ_CLOSE	                            C:\Documents and Settings\Administrator\Application Data\URE\TYPES.RDB SUCCESS

The following table shows what data files are accessed/read during startup. The times are currently summed up for the initial access. Many files are read on demand later during the startup process. The table provides two times for every entry as there are operations which are processed asynchronously, most often this is IRP_MJ_CREATE where IRP_MJ_READ is most of the time synchronously.

Order of Read/Write Data file Size (bytes) Time (ms) elapsed / i/o time
001 soffice.ini 165 12ms elapsed / 23ms i/o
002 fundamental.ini 1.028 16ms / 29ms
003 URE\bin\uno.ini 322 1ms / 1ms
004 fundamentalbasis.ini 1.010 23ms / 45ms
005 Basis\program\uno.ini 510 1ms / 1ms
006 boostrap.ini 240 1ms / 1ms
007 types.rdb 851.968 79ms / 131ms
008 offapi.rdb 6.839.760 96ms / 155ms
009 oovbaapi.rdb 1.802.240 59ms / 94ms
010 OpenOffice.org 3\URE\misc\services.rdb 262.144 59ms / 112ms
011 OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.component.PackageRegistryBackend\common.rdb 8.192 29ms / 39ms
012 OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.component.PackageRegistryBackend\Windows_x86.rdb 2.048 9ms / 15ms
Retrieved from "https://wiki.openoffice.org/w/index.php?title=Performance/OOo31_LibrariesOnStartup&oldid=112090"
Personal tools