Difference between revisions of "Performance/OOo31 LibrariesOnStartup"
(→Superfetch) |
m (→How to tackle the poor start up performance) |
||
Line 1,777: | Line 1,777: | ||
** One cause could be the high amount of files and folders which are accessed during start up ( ~100 libraries and more than 200 data files/pathes). | ** One cause could be the high amount of files and folders which are accessed during start up ( ~100 libraries and more than 200 data files/pathes). | ||
** The nesting of folders is also very high. | ** The nesting of folders is also very high. | ||
− | ** Libraries and binaries are now spread over three different folders: OpenOffice.org/program, OpenOffice.org/Basis/program and OpenOfficer.org/URE/bin. The bad thing is that Windows uses a defined searching schema (at least one function starting from Windows XP SP1 can influence it, see SetDllDirectory()). That means that Windows first searches for OpenOffice.org libraries within folders which don't contain any. | + | ** Libraries and binaries are now spread over three different folders: OpenOffice.org/program, OpenOffice.org/Basis/program and OpenOfficer.org/URE/bin. The bad thing is that Windows uses a defined searching schema (at least one function starting from Windows XP SP1 can influence it, see SetDllDirectory()). That means that Windows first searches for OpenOffice.org libraries within folders which don't contain any. More information about this problem and how it degrades performance can be found here: [http://msdn.microsoft.com/en-us/library/ms810432.aspx http://msdn.microsoft.com/en-us/library/ms810432.aspx] |
*** Look beside the executable. | *** Look beside the executable. | ||
*** Look into the folder defined by "SetDllDirectory()". | *** Look into the folder defined by "SetDllDirectory()". |
Revision as of 15:18, 8 April 2009
|
---|
Quick Navigation Team Communication Activities |
About this template |
Contents
- 1 Performance analysis for OpenOffice.org 3.1 startup (Windows)
- 2 OpenOffice.org libraries
- 3 File I/O during OpenOffice.org startup
- 4 Summary
- 5 How to tackle the poor start up performance
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 performance analysis under Windows
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. Most of the analysis data was retrieved using the Process Monitor tool. This tool provides powerful functions to get information which are normally buried deep in the Windows system.
Windows features which can influence start up performance
Microsoft implemented new features into Windows XP, Windows 2003 and Windows Vista which can influence the start up performance of applications. First this is a nice way to help applications to start faster but it can disturb performance analysis. The following descriptions want to show some of the features and how they influence the start up performance.
Prefetch
- Windows XP, Windows Server 2003
This feature tracks how an application accesses code and data files during start up. The access pattern is written into prefetch files (.pf) which are stored within the Prefetch folder in the root Windows directory ("\Windows\Prefetch"). Only the first 10 seconds of application activity are monitored and stored. On the next application start up Windows tries to optimize the file access based on the previously stored access pattern. This prefetching can easily be seen in the Process Monitor where Windows tries to load bigger chunks of a library with asynchronous file I/O. It leads to the fact that ProcessMonitor provides in the "File Summary" function very high file I/O times. This feature can lead to better OpenOffice.org start up times (about 10-20%). Deleting a prefetch file results in a normal start up.
More information can be found here:
Superfetch
- Windows Vista, Windows Server 2008
An enhanced feature which is based on prefetch. It loads often used application into non-used memory. This feature can massively influence start up performance, especially if the test machine contains plenty of memory. It's possible that applications can be preloaded after a reboot, so some applications start lightning fast. For testing purposes this can be very disturbing and lead to non-reproducible results.
More information and how to disable this feature can be found here:
- http://en.wikipedia.org/wiki/Superfetch#SuperFetch
- http://blogs.technet.com/askperf/archive/2007/03/29/windows-vista-superfetch-readyboost.aspx
- http://www.howtogeek.com/howto/windows-vista/how-to-disable-superfetch-on-windows-vista/
Disk Defragmenter
- Since Windows 2000
Since Windows 2000 Microsoft provides a tool to defragment disk drives. File fragmentation can have a significant impact on start up performance when data must be read from a disk drive. Whenever comparisons are made between different installations it should be ensured that these installations don't suffer from fragmentation.
More information: http://en.wikipedia.org/wiki/Disk_Defragmenter_(Windows)
Overview about the system activities of OpenOffice.org/svdem.exe 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" - 5400rpm - UDMA100 - 16MB Cache
- Anti-Virus Real-Time Protection (Symantec Antivirus Corporate Edition)
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 OpenOffice.org
The cold startup time for OpenOffice.org DEV300m40 on this machine:
Measure point | Time/s (without AV) | Time/s (AV realtime protection) |
---|---|---|
Splash Screen | ~6,2 sec. | ~14 sec. |
Start Center up and running | ~13,5 sec. | ~22 secs. |
Writer up and running | ~24,8 sec. | ~33 secs. |
The following image shows the soffice.bin process activitiy during startup of the Writer module without any AV real-time protection.
Process Monitor summary data:
System activity | Number (with AV) | Number (without AV) |
---|---|---|
File Events | 33.988 | 29.349 |
Registry Events | 2.364 | 3.415 |
Network Events | 0 | 0 |
Max. CPU utilization | 32% total / 21% kernel | 37% total / 20% kernel |
CPU time | USER=1,54 sec. / KERNEL=2,82 sec. | USER=1,22 sec. / KERNEL=1,44 sec. |
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 partially used.
Warm startup OpenOffice.org
The warm startup time for OpenOffice.org DEV300m40 on this machine:
Measure point | Time/s (without AV) | Time/s (AV realtime protection) |
---|---|---|
Splash Screen | ~1,3 sec. | ~1,4 sec. |
Start Center up and running | ~2,5 sec. | ~2.6 secs. |
Writer up and running | ~4.0 sec. | ~4,5 secs. |
System activity | Number (with AV) | Number (without AV) |
---|---|---|
File Events | 31.937 | 24.718 |
Registry Events | 2.284 | 2.284 |
Network Events | 0 | 0 |
Max. CPU utilization | 78% total / 38% kernel | 79% total / 33% kernel |
CPU time | USER=1,33 sec. / KERNEL=1,65 sec. | USER=1,28 sec. / KERNEL=1,16 sec. |
- On warm start OpenOffice.org is much more balanced between file I/O and CPU.
Cold startup svdem.exe (minimal VCL application)
The cold startup time for svdem.exe DEV300m40 on this machine:
Measure point | Time/s (without AV) |
---|---|
svdem.exe up and running | ~4,0 sec. |
The following image shows the soffice.bin process activitiy during startup of the Writer module without any AV real-time protection.
Process Monitor summary data:
System activity | Number (without AV) |
---|---|
File Events | 1.730 |
Registry Events | 609 |
Network Events | 0 |
Max. CPU utilization | 6,2 % total / 6,2 % kernel |
CPU time | USER=0,062 sec. / KERNEL=0,141 sec. |
What can be see from the summary?
- On cold start svdem.exe is strongly I/O and not CPU bound. Even on this slow system the CPU power is not really used.
Warm startup svdem.exe (minimal VCL application)
The warm startup time for svdem.exe DEV300m40 on this machine:
Measure point | Time/s (without AV) |
---|---|
svdem.exe up and running | ~0,7 sec. |
The following image shows the svdem.exe process activitiy during startup without any AV real-time protection.
Process Monitor summary data:
System activity | Number (without AV) |
---|---|
File Events | 2.439 |
Registry Events | 609 |
Network Events | 0 |
Max. CPU utilization | 0 % total / 0 % kernel |
CPU time | USER=0,015 sec. / KERNEL=0,188 sec. |
What can be see from the summary?
- On warm start svdem.exe is now much less I/O dependent and start up time is about 1/6 of the cold start scenario.
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
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. The previous measurements were made with an active anti virus scanner in the background which was responsible for many file I/O requests while loading libraries and access to zip files (e.g. images.zip). These additional access were done on system level as the AV scanner package used a driver. While there many Windows systems which use a real time AV system this circumstance needs to be viewed separately. Therefore I made new measurements with a clean non-av influenced system.
This snippet below has been directly copied from the output of Process Monitor (some line of registry access and process switches were removed) 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.
Some explanations for the content of the log file:
- C:\$Mft (Master File Table)
Time (hh:mm:ss) Dur. (s) Executable PID TID Function Path/File/Name Result Parameters -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 10:39:48,2426100 0.0000121 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 10:39:48,2427433 0.0000154 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system32\sal3.dll NAME NOT FOUND 10:39:48,2428696 0.0000084 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system\sal3.dll NAME NOT FOUND 10:39:48,2429593 0.0000120 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\sal3.dll NAME NOT FOUND 10:39:48,2431830 0.0000106 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 10:39:48,2539665 0.0000109 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll NAME NOT FOUND 10:39:48,2692182 0.0013496 soffice.bin 3776 3780 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 10:39:48,2692584 0.0012943 soffice.bin 3776 3780 IRP_MJ_READ C:\$Mft SUCCESS Offset: 34.451.456, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 10:39:48,2706625 0.0000115 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 10:39:48,2707871 0.0000154 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system32\sal3.dll NAME NOT FOUND 10:39:48,2709237 0.0000084 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system\sal3.dll NAME NOT FOUND 10:39:48,2710117 0.0000112 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\sal3.dll NAME NOT FOUND 10:39:48,2711072 0.0000098 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 10:39:48,2712260 0.0000100 soffice.bin 3776 3780 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll NAME NOT FOUND 10:39:48,2713377 0.0000062 soffice.bin 3776 3780 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 10:39:48,2714481 0.0000125 soffice.bin 3776 3780 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 10:39:48,2715464 0.0000028 soffice.bin 3776 3780 FASTIO_ACQUIRE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS SyncType: SyncTypeCreateSection, PageProtection: PAGE_EXECUTE 10:39:48,2715545 0.0000028 soffice.bin 3776 3780 FASTIO_QUERY_INFORMATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS Type: QueryStandardInformationFile, AllocationSize: 1.732.608, EndOfFile: 1.732.608, NumberOfLinks: 1, DeletePending: False, Directory: False 10:39:48,2715621 0.0000019 soffice.bin 3776 3780 FASTIO_ACQUIRE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS SyncType: SyncTypeOther 10:39:48,2715676 0.0000020 soffice.bin 3776 3780 FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 10:39:48,2716176 0.0001584 soffice.bin 3776 3780 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 10:39:48,2717936 0.0000023 soffice.bin 3776 3780 FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 10:39:48,2718001 0.0000019 soffice.bin 3776 3780 FASTIO_ACQUIRE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS SyncType: SyncTypeOther 10:39:48,2718057 0.0000016 soffice.bin 3776 3780 FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 10:39:48,2719283 0.0000042 soffice.bin 3776 3780 IRP_MJ_CLEANUP C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 10:39:48,2721012 0.0000000 soffice.bin 3776 3780 Load Image C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS Image Base: 0x60100000, Image Size: 0x1ae000 10:39:48,2727661 0.0220489 soffice.bin 3776 3780 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 10:39:48,2950497 0.0000139 soffice.bin 3776 3780 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 10:39:48,2952444 0.0000120 soffice.bin 3776 3780 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
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 executed in the context of a previous function, others are executed asynchronously. The output from Process Monitor shows us that libraries are not read in one portion into the address space of a process. Windows always load the first page into memory and other are paged in on-demand via page faults.
It's interesting to see that the sum of durations for the initial part of sal3 needs ~23,6ms (the FASTIO_NETWORK_QUERY_OPEN initiated the IRP_MJ_READ C:\$Mft therefore these times cannot be added). The total elapsed time is ~52,6ms. So about 44% of the time was used for system 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 23,6 ms sounds not very much but at that point two pages (two IRP_MJ_READ requests) have been loaded into memory. If you look at the number of libraries and their size it's possible this can grow to huge times!
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.
As far as I can see most OpenOffice.org libraries could be loaded at the rebased address. There are some clashes with system libraries.
The following two tables try to show what time is spent for all libraries that are loaded during. This is necessary as the order of library loading is different starting swriter.exe or soffice.exe. 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. The column "without AV" shows now the whole time that is used to page-in the library parts that are needed during startup. The column "with AV" shows only the initial part, although the AV scanner reads many pages from the library on the first open. The first table shows the Writer startup (start "swriter.exe").
Table of library loading times - Writer cold startup (swriter.exe)
Order of Loading | Library/Executable | Size | Time(ms) with AV (intial loading) | Time(ms) without AV (whole page-in time) |
---|---|---|---|---|
001 | soffice.bin | 7.418.368 | 691 | 78 |
002 | sal3.dll | 1.732.608 | 183 | 101 |
003 | uwinapi.dll | 86.016 | 72 | 14 |
004 | sofficeapp.dll | 326.144 | 168 | 93 |
005 | comphelp4MSC.dll | 948.224 | 361 | 229 |
006 | cppuhelper3MSC.dll | 431.104 | 364 | 105 |
007 | salhelper3MSC.dll | 13.824 | 56 | 10 |
008 | cppu3.dll | 143.360 | 139 | 26 |
009 | stlport_vc7145.dll | 597.504 | 253 | 62 |
010 | ucbhelper4MSC.dll | 356.864 | 153 | 65 |
011 | vos3MSC.dll | 94.208 | 56 | 7 |
012 | i18nisolang1MSC.dll | 24.576 | 95 | 12 |
013 | sfxmi.dll | 3.110.912 | 492 | 755 |
014 | fwemi.dll | 849.408 | 170 | 142 |
015 | fwimi.dll | 299.008 | 103 | 84 |
016 | utlmi.dll | 465.920 | 234 | 106 |
017 | tlmi.dll | 509.952 | 190 | 122 |
018 | basegfxmi.dll | 572.928 | 234 | 71 |
019 | vclmi.dll | 3.074.048 | 300 | 602 |
020 | sotmi.dll | 257.024 | 100 | 43 |
021 | i18nutilMSC.dll | 67.072 | 49 | 15 |
022 | icuuc40.dll | 949.760 | 194 | 135 |
023 | icudt40.dll | 13.912.064 | 70 | 54 |
024 | svlmi.dll | 724.992 | 172 | 178 |
025 | svtmi.dll | 2.884.608 | 473 | 533 |
026 | tkmi.dll | 1.870.336 | 322 | 227 |
027 | jvmfwk3.dll | 89.088 | 65 | 26 |
028 | libxml2.dll | 970.752 | 215 | 154 |
029 | sbmi.dll | 1.310.208 | 712 | 215 |
030 | xcrmi.dll | 529.920 | 151 | 67 |
031 | saxmi.dll | 80.384 | 47 | 12 |
032 | jmi_g.dll | 32.768 | 22 | 2 |
033 | jvmaccess3MSC.dll | 25.600 | 45 | 28 |
034 | msci_uno.dll | 52.224 | 70 | 10 |
035 | bootstrap.dll | 453.632 | 121 | 43 |
036 | reg3.dll | 99.328 | 84 | 17 |
037 | store3.dll | 78.336 | 57 | 3 |
038 | unsafe_uno_uno.dll | 12.800 | 45 | 5 |
039 | purpenvhelper3MSC.dll | 18.432 | 62 | 1 |
040 | configmgr2.uno.dll | 1.432.064 | 219 | 176 |
041 | stocservices.uno.dll | 92.672 | 87 | 8 |
042 | sysmgr1.dll | 37.888 | 68 | 18 |
043 | sax.uno.dll | 135.680 | 101 | 14 |
044 | localebe1.uno.dll | 30.208 | 85 | 1 |
045 | behelper.uno.dll | 31.232 | 63 | 1 |
046 | splmi.dll | 148.992 | 100 | 3 |
047 | ucb1.dll | 197.632 | 65 | 15 |
048 | fwlmi.dll | 106.496 | 84 | 3 |
049 | ucpfile1.dll | 245.248 | 121 | 36 |
050 | fwkmi.dll | 1.879.552 | 265 | 563 |
051 | uuimi.dll | 198.144 | 90 | 47 |
052 | filterconfig1.dll | 188.416 | 89 | 40 |
053 | dnd.dll | 115.200 | 54 | 46 |
054 | swmi.dll | 7.332.352 | 543 | 2400 |
055 | lngmi.dll | 982.016 | 210 | 294 |
056 | xomi.dll | 2.898.432 | 331 | 237 |
057 | svxmi.dll | 9.172.992 | 556 | 2324 |
058 | avmediami.dll | 56.832 | 133 | 149 |
059 | gomi.dll | 295.936 | 166 | 180 |
060 | drawinglayermi.dll | 802.304 | 199 | 123 |
061 | canvastoolsmi.dll | 498.176 | 201 | 159 |
062 | aggmi.dll | 129.024 | 116 | 69 |
063 | cppcanvasmi.dll | 285.184 | 146 | 105 |
064 | i18npool.uno.dll | 1.235.456 | 236 | 130 |
065 | icuin40.dll | 1.052.160 | 227 | 202 |
066 | localedata_euro.dll | 642.048 | 184 | 74 |
067 | localedata_en.dll | 104.448 | 71 | 42 |
068 | unoxmlmi.dll | 280.064 | 144 | 85 |
069 | fileacc.dll | 52.224 | 35 | 3 |
070 | package2.dll | 248.320 | 114 | 119 |
071 | fsstorage.uno.dll | 94.208 | 81 | 4 |
072 | xstor.dll | 239.616 | 111 | 75 |
073 | reflection.uno.dll | 99.840 | 88 | 35 |
074 | guesslangmi.dll | 36.864 | 45 | 31 |
075 | libtextcat.dll | 14.848 | 59 | 57 |
076 | deploymentmi.uno.dll | 266.240 | 156 | 80 |
077 | deploymentmiscmi.dll | 100.864 | 86 | 25 |
078 | libdb42.dll | 541.184 | 111 | 146 |
079 | helplinkermi.dll | 134.144 | 40 | 29 |
080 | libxslt.dll | 166.400 | 90 | 41 |
081 | ucpexpand1.uno.dll | 24.576 | 37 | 22 |
082 | introspection.uno.dll | 98.816 | 86 | 55 |
083 | updchk.uno.dll | 166.912 | ?? | 28 |
084 | libcurl.dll | 121.344 | 38 | 54 |
085 | updatefeed.uno.dll | 77.824 | 8 | 30 |
086 | updchkmi.dll | 48.640 | 58 | 37 |
087 | resmi.dll | 65.024 | 88 | 37 |
088 | oleautobridge.uno.dll | 280.576 | 134 | 61 |
089 | emsermi.dll | 148.992 | 83 | 6 |
090 | ldapbe2.uno.dll | 83.968 | 47 | 40 |
091 | nsldap32v50.dll | 139.264 | 99 | 40 |
092 | sysdtrans.dll | 107.008 | 55 | 34 |
093 | ftrans1.dll | 50.688 | 63 | 31 |
094 | mcnttype.dll | 33.792 | 44 | 14 |
Empty Writer document up and running | 79.384.014 | 33120ms elapsed / >14282ms libs i/o time | 24800ms elapsed / 13012ms i/o read |
The following chapter wants to make a summary about cold startup time and the impact of the aspect loading libraries.
Summary
Currently the summary just look at the statistic data from the normal cold startup (without AV software).
Aspect | Time | Perctange |
---|---|---|
Writer startup | 24800ms | 100 % |
Load OpenOffice.org libraries (file I/O) | 13012ms | 52,5 % |
Load Windows libraries (file I/O) | 242ms | 0,97 % |
Library loading, in this case synchronous page in of missing code/data, make more than half of the startup time.
Process Monitor results - svdem.exe cold startup
Table of library loading times - svdem.exe cold startup
Order of Loading | Library/Executable | Size | time (ms) without AV (whole page-in time) |
---|---|---|---|
001 | svdem.exe | 15360 | 25 |
002 | cppuhelper3MSC.dll | 431.104 | 127 |
003 | sal3.dll | 1.732.608 | 171 |
004 | uwinapi.dll | 86.016 | 92 |
005 | salhelper3MSC.dll | 13.824 | 42 |
006 | cppu3.dll | 143.360 | 94 |
007 | stlport_vc7145.dll | 597.504 | 214 |
008 | tlmi.dll | 509.952 | 160 |
009 | vos3MSC.dll | 94.208 | 41 |
010 | basegfxmi.dll | 572.928 | 100 |
011 | i18nisolang1MSC.dll | 24.576 | 47 |
012 | comphelp4MSC.dll | 948.224 | 128 |
013 | ucbhelper4MSC.dll | 356.864 | 62 |
014 | vclmi.dll | 3.074.048 | 490 |
015 | sotmi.dll | 257.024 | 79 |
016 | utlmi.dll | 465.920 | 96 |
017 | i18nutilMSC.dll | 67072 | 44 |
018 | icuuc40.dll | 949760 | 75 |
019 | icudt40.dll | 13912064 | 9 |
020 | bootstrap.uno.dll | 453.632 | 128 |
021 | reg3.dll | 99.328 | 91 |
022 | store3.dll | 78.336 | 70 |
023 | msci_uno.dll | 52.224 | 86 |
024 | unsafe_uno_uno.dll | 12.800 | 37 |
025 | purpenvhelper3MSC.dll | 18.432 | 28 |
026 | tkmi.dll | 1.870.336 | 179 |
Total | 4010ms / 2715ms file I/O |
Summary
Currently the summary just looks at the statistic data from the normal cold startup (without AV software).
Aspect | Time | Perctange |
---|---|---|
svdem.exe startup | 4010ms | 100 % |
Load OpenOffice.org libraries (file I/O) | 2715ms | 67,7 % |
Load Windows libraries (file I/O) | 181ms | 4,51 % |
Library loading, in this case synchronous page in of missing code/data, makes more 70% of the start up 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 Parameters ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 11:19:55,6239718 0.0000140 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 11:19:55,6240902 0.0000174 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system32\sal3.dll NAME NOT FOUND 11:19:55,6242134 0.0000087 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system\sal3.dll NAME NOT FOUND 11:19:55,6242992 0.0000126 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\sal3.dll NAME NOT FOUND 11:19:55,6251851 0.0000111 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 11:19:55,6253063 0.0000120 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll NAME NOT FOUND 11:19:55,6254278 0.0000081 soffice.bin 2628 2568 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:19:55,6255167 0.0000095 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 11:19:55,6256262 0.0000123 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system32\sal3.dll NAME NOT FOUND 11:19:55,6257379 0.0000081 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\system\sal3.dll NAME NOT FOUND 11:19:55,6275298 0.0000112 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\WINDOWS\sal3.dll NAME NOT FOUND 11:19:55,6276237 0.0000095 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\program\sal3.dll NAME NOT FOUND 11:19:55,6277357 0.0000106 soffice.bin 2628 2568 FASTIO_NETWORK_QUERY_OPEN C:\Program Files\OpenOffice.org 3\Basis\program\sal3.dll NAME NOT FOUND 11:19:55,6278460 0.0000065 soffice.bin 2628 2568 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:19:55,6279530 0.0000098 soffice.bin 2628 2568 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:19:55,6279712 0.0000025 soffice.bin 2628 2568 FASTIO_ACQUIRE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS SyncType: SyncTypeCreateSection, PageProtection: PAGE_EXECUTE 11:19:55,6279796 0.0000019 soffice.bin 2628 2568 FASTIO_ACQUIRE_FOR_CC_FLUSH C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 11:19:55,6279910 0.0000023 soffice.bin 2628 2568 FASTIO_RELEASE_FOR_CC_FLUSH C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 11:19:55,6279972 0.0000019 soffice.bin 2628 2568 FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 11:19:55,6280033 0.0000020 soffice.bin 2628 2568 FASTIO_ACQUIRE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS SyncType: SyncTypeOther 11:19:55,6280089 0.0000017 soffice.bin 2628 2568 FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 11:19:55,6281307 0.0000042 soffice.bin 2628 2568 IRP_MJ_CLEANUP C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 11:19:55,6287501 0.0000033 soffice.bin 2628 2568 IRP_MJ_CLOSE C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS 11:19:55,6289015 0.0000000 soffice.bin 2628 2568 Load Image C:\Program Files\OpenOffice.org 3\URE\bin\sal3.dll SUCCESS Image Base: 0x60100000, Image Size: 0x1ae000 11:19:55,6291426 0.0000162 soffice.bin 2628 2568 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:19:55,6297711 0.0000129 soffice.bin 2628 2568 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
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 for file i/o requests is ~0.2ms and the elapsed time ~6ms.
Process Monitor results - svdem.exe warm startup
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). Some information about the log output you can see below.
- C:\$Mft - "Master File Table" of NTFS. The Master File Table contains metadata about every file, directory, and metafile on a NTFS volume.
- IRP - I/O request packet
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
The log from Process Monitor shows us that even small data files can lead to a certain delay in the startup process. In this example reading the soffice.ini file required access to the NTFS master file table (IRP_MJ_READ with C:\$Mft) which gives us a penalty of about 11ms for opening the file (IRP_MJ_CREATE). In the end reading the 177 bytes from soffice.ini needs about 12,5ms. So in the cold start up scenario accessing many (small) files can have a serious impact on start up performance.
The following tables shows what data files (also NTFS system files) and paths are accessed/read during startup. The times are for total file I/O in descending order (only synchronous read operations are included).
Order | Path/File | Size (byte) | Time (ms) |
---|---|---|---|
001 | C:\$Mft (Master File Table - NTFS system file) | - | 1.491 |
002 | C:\Program Files\OpenOffice.org 3\Basis\program\services.rdb | - | 1.409 |
003 | C:\Program Files\OpenOffice.org 3\Basis\program\offapi.rdb | - | 1.202 |
004 | C:\Program Files\OpenOffice.org 3\Basis\share\config\images.zip | - | 260 |
005 | C:\Program Files\OpenOffice.org 3\URE\misc\types.rdb | - | 235 |
006 | C:\Program Files\OpenOffice.org 3\Basis\program\oovbaapi.rdb | - | 206 |
007 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\swen-US.res | - | 108 |
008 | C:\$Directory (NTFS system file) | - | 81 |
009 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\svxen-US.res | - | 74 |
010 | C:\Program Files\OpenOffice.org 3\Basis\help\en\swriter.db | - | 65 |
011 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\svten-US.res | - | 57 |
012 | C:\Program Files\OpenOffice.org 3\URE\misc\services.rdb | - | 53 |
013 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\data\org\openoffice\Office\UI | - | 50 |
014 | C:\WINDOWS\Fonts\times.ttf | - | 50 |
015 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Addons.dat | - | 45 |
016 | C:\Program Files\OpenOffice.org 3\Basis\help\en\swriter.ht | - | 42 |
017 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\vclen-US.res | - | 40 |
018 | C:\Program Files\OpenOffice.org 3\Basis\share\config\soffice.cfg\modules\swriter\toolbar | - | 39 |
019 | C:\Program Files\OpenOffice.org 3\program\soffice.bin | - | 38 |
020 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Jobs.dat | - | 38 |
021 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.WriterWeb.dat | - | 34 |
022 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.UI.Factories.dat | - | 33 |
023 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.UI.dat | - | 27 |
024 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Logging.dat | - | 27 |
025 | C:\Program Files\OpenOffice.org 3\Basis\program | - | 27 |
026 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache | - | 26 |
027 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.TypeDetection.Filter.dat | - | 25 |
028 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.SFX.dat | - | 25 |
029 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\res\en-US\org\openoffice\Office\UI | - | 24 |
030 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.TypeDetection.Misc.dat | - | 23 |
031 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.UI.WriterWindowState.dat | - | 23 |
032 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.configuration.PackageRegistryBackend\registered_packages.db | - | 23 |
033 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\sfxen-US.res | - | 23 |
034 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.UI.GenericCommands.dat | - | 22 |
035 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Setup.xcu | - | 22 |
036 | C:\Program Files\OpenOffice.org 3\program\intro.bmp | - | 21 |
037 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\1B.tmp_\dict-en.oxt\description.xml | - | 21 |
038 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.TypeDetection.Types.dat | - | 21 |
039 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\updchken-US.res | - | 21 |
040 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Office | - | 21 |
041 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.UI.Controller.dat | - | 21 |
042 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.component.PackageRegistryBackend | - | 20 |
043 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Views.dat | - | 20 |
044 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Compatibility.dat | - | 20 |
045 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Office\Views.xcu | - | 20 |
046 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\modules\org\openoffice\TypeDetection\Types | - | 19 |
047 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.UI.WriterCommands.dat | - | 19 |
048 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\data\org\openoffice | - | 19 |
049 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\german.lm | - | 19 |
050 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\res\en-US\org\openoffice\Office | - | 18 |
051 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\21,tmp_\writer2latex.oxt | - | 18 |
052 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\FormWizard | - | 18 |
053 | C:\WINDOWS\Fonts\tahoma.ttf | - | 17 |
054 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Depot\script.xlb | - | 17 |
055 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\uno_packages\cache\uno_packages.db | - | 17 |
056 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages.db | - | 17 |
057 | C:\Program Files\OpenOffice.org 3\Basis\share\config\soffice.cfg\modules | - | 16 |
058 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Depot | - | 15 |
059 | C:\Program Files\OpenOffice.org 3\share\config\images_brand.zip | - | 15 |
060 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\1F.tmp_\dict-fr.oxt\description.xml | - | 15 |
061 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Writer.dat | - | 15 |
062 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.VCL.dat | - | 15 |
063 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\fween-US.res | - | 15 |
064 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Office\Common.xcu | - | 15 |
065 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\swahili.lm | - | 14 |
066 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\deploymenten-US.res | - | 14 |
067 | C:\Program Files\OpenOffice.org 3\Basis\share\config\soffice.cfg\modules\swriter\toolbar\standardbar.xml | - | 14 |
068 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.component.PackageRegistryBackend\Windows_x86_.rdb | - | 14 |
069 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\modules\org\openoffice\Setup | - | 14 |
070 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Inet.dat | - | 13 |
071 | C:\WINDOWS\system32\config\system | - | 13 |
072 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.UserProfile.dat | - | 13 |
073 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Schedule | - | 13 |
074 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\belarus.lm | - | 13 |
075 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\modules\org\openoffice\TypeDetection\Misc | - | 13 |
076 | C:\Program Files\OpenOffice.org 3\Basis\program\resource | - | 13 |
077 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\uno_packages\cache\registry\com.sun.star.comp.deployment.configuration.PackageRegistryBackend\registered_packages.db | - | 13 |
078 | C:\Program Files\OpenOffice.org 3\Basis\share\config\soffice.cfg\modules\swriter\toolbar\textobjectbar.xml | - | 13 |
079 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\modules\org\openoffice\Office\Linguistic | - | 12 |
080 | C:\Program Files\OpenOffice.org 3\Basis\share\config\soffice.cfg\modules\swriter\menubar\menubar.xml | - | 12 |
081 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.component.PackageRegistryBackend\common_.rdb | - | 12 |
082 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\korean.lm | - | 12 |
083 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\dialog.xlc | - | 12 |
084 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.TypeDetection.dat | - | 11 |
085 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\data\org\openoffice\Office | - | 11 |
086 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\french.lm | - | 10 |
087 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\afrikaans.lm | - | 10 |
088 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\croatian.lm | - | 10 |
089 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Gimmicks | - | 10 |
090 | C:\Program Files\OpenOffice.org 3\Basis\share\basic | - | 9 |
091 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Euro | - | 8 |
092 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\modules\org\openoffice\Office\Common | - | 8 |
093 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\script.xlc | - | 8 |
094 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\hindi.lm | - | 8 |
095 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\hungarian.lm | - | 8 |
096 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\danish.lm | - | 8 |
097 | C:\Program Files\OpenOffice.org 3\Basis\share\config\soffice.cfg\modules\swriter\statusbar\statusbar.xml | - | 8 |
098 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\malay.lm | - | 7 |
099 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Tools | - | 7 |
100 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\fpdb.conf | - | 7 |
101 | C:\Program Files\OpenOffice.org 3\Basis\help | - | 7 |
102 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\english.lm | - | 7 |
103 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\sanskrit.lm | - | 7 |
104 | C:\Program Files\OpenOffice.org 3\Basis\share\registry\modules\org\openoffice\TypeDetection\Filter | - | 7 |
105 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\persian.lm | - | 7 |
106 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Paths.dat | - | 7 |
107 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\norwegian.lm | - | 6 |
108 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\chinese_simplified.lm | - | 6 |
109 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Template | - | 5 |
110 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\estonian.lm | - | 5 |
111 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\indonesian.lm | - | 5 |
112 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\breton.lm | - | 4 |
113 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\hebrew.lm | - | 4 |
114 | C:\Program Files\OpenOffice.org 3\program\fundamental.ini | - | 3 |
115 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\vietnamese.lm | - | 1 |
116 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\manx_gaelic.lm | - | 1 |
117 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\thai.lm | - | 1 |
118 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Office\Jobs.xcu | - | 0,5 |
119 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Setup.dat | - | 0,4 |
120 | C:\Program Files\OpenOffice.org 3\program\resource\oooen-US.res | - | 0,4 |
121 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Common.dat | - | 0,4 |
122 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\stten-US.res | - | 0,3 |
123 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\upden-US.res | - | 0,3 |
124 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\ukrainian.lm | - | 0,3 |
125 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\frisian.lm | - | 0,2 |
126 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Linguistic.dat | - | 0,2 |
127 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\ImportWizard | - | 0,2 |
128 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\yiddish_utf.lm | - | 0,2 |
129 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\scots.lm | - | 0,2 |
130 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\czech.lm | - | 0,2 |
131 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\quechua.lm | - | 0,2 |
132 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\welsh.lm | - | 0,2 |
133 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\esperanto.lm | - | 0,2 |
134 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\latvian.lm | - | 0,2 |
135 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\romanian.lm | - | 0,2 |
136 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\scots_gaelic.lm | - | 0,2 |
137 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\dutch.lm | - | 0,2 |
138 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\swedish.lm | - | 0,2 |
139 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\amharic_utf.lm | - | 0,2 |
140 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\lithuanian.lm | - | 0,2 |
141 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\italian.lm | - | 0,2 |
142 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\albanian.lm | - | 0,2 |
143 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\slovak_ascii.lm | - | 0,2 |
144 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\catalan.lm | - | 0,2 |
145 | C:\Program Files\OpenOffice.org 3\Basis\program\configmgr.ini | - | 0,2 |
146 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\greek.lm | - | 0,2 |
147 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\portuguese.lm | - | 0,2 |
148 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\serbian_ascii.lm | - | 0,2 |
149 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\chinese_traditional.lm | - | 0,2 |
150 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\tamil.lm | - | 0,2 |
151 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\irish_gaelic.lm | - | 0,1 |
152 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\russian.lm | - | 0,1 |
153 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\icelandic.lm | - | 0,1 |
154 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\sben-US.res | - | 0,1 |
155 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\finnish.lm | - | 0,1 |
156 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\georgian.lm | - | 0,1 |
157 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\bosnian.lm | - | 0,1 |
158 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\polish.lm | - | 0,1 |
159 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\latin.lm | - | 0,1 |
160 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Histories.dat | - | 0,1 |
161 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\romansh.lm | - | 0,1 |
162 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\turkish.lm | - | 0,1 |
163 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\tagalog.lm | - | 0,1 |
164 | C:\Program Files\OpenOffice.org 3\Basis\program\fundamentalbasis.ini | - | 0,1 |
165 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\marathi.lm | - | 0,1 |
166 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.ucb.Configuration.dat | - | 0,1 |
167 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Substitution.dat | - | 0,1 |
168 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\spanish.lm | - | 0,1 |
169 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\nepali.lm | - | 0,1 |
170 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\basque.lm | - | 0,1 |
171 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.ProtocolHandler.dat | - | 0,1 |
172 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\slovenian.lm | - | 0,1 |
173 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\japanese.lm | - | 0,1 |
174 | C:\Program Files\OpenOffice.org 3\Basis\share\fingerprint\arabic.lm | - | 0,1 |
175 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\ofaen-US.res | - | 0,1 |
176 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Recovery.dat | - | 0,1 |
177 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Gimmicks\script.xlb | - | 0,0 |
178 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\1D.tmp_\dict-es.oxt\description.xml | - | 0,0 |
179 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\basic\Standard\Module1,xba | - | 0,0 |
180 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.LDAP.dat | - | 0,0 |
181 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\uno_packages\cache\log.txt | - | 0,0 |
182 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\basic\dialog.xlc | - | 0,0 |
183 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Commands.dat | - | 0,0 |
184 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Office\Linguistic.xcu | - | 0,0 |
185 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Office\Writer.xcu | - | 0,0 |
186 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\basic\script.xlc | - | 0,0 |
187 | C:\Program Files\OpenOffice.org 3\program\version.ini | - | 0,0 |
188 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.System.dat | - | 0,0 |
189 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\1F.tmp_\dict-fr.oxt\META-INF\manifest.xml | - | 0,0 |
190 | C:\Program Files\OpenOffice.org 3\Basis\program\uno.ini | - | 0,0 |
191 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\ScriptBindingLibrary\dialog.xlb | - | 0,0 |
192 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.Events.dat | - | 0,0 |
193 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.UI.GlobalSettings.dat | - | 0,0 |
194 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.component.PackageRegistryBackend\Windows_x86rc | - | 0,0 |
195 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\21,tmp_\writer2latex.oxt\description.xml | - | 0,0 |
196 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\21,tmp_\writer2latex.oxt\META-INF\manifest.xml | - | 0,0 |
197 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\basic\Standard\script.xlb | - | 0,0 |
198 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Depot\dialog.xlb | - | 0,0 |
199 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\FormWizard\dialog.xlb | - | 0,0 |
200 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\ImportWizard\dialog.xlb | - | 0,0 |
201 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Schedule\dialog.xlb | - | 0,0 |
202 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Schedule\script.xlb | - | 0,0 |
203 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Template\script.xlb | - | 0,0 |
204 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Tools\dialog.xlb | - | 0,0 |
205 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\1B.tmp_\dict-en.oxt\META-INF\manifest.xml | - | 0,0 |
206 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.Office.TabBrowse.dat | - | 0,0 |
207 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Euro\dialog.xlb | - | 0,0 |
208 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\basic\Standard\dialog.xlb | - | 0,0 |
209 | C:\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\cache\org.openoffice.ucb.Store.dat | - | 0,0 |
210 | 0 :\Documents and Settings\Administrator\Application Data\OpenOffice.org\3\user\registry\data\org\openoffice\Office\Recovery.xcu | - | 0,0 |
211 | C:\Program Files\OpenOffice.org 3\Basis\program\version.ini | - | 0,0 |
212 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Euro\script.xlb | - | 0,0 |
213 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\FormWizard\script.xlb | - | 0,0 |
214 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\ImportWizard\script.xlb | - | 0,0 |
215 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\ScriptBindingLibrary\script.xlb | - | 0,0 |
216 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Template\dialog.xlb | - | 0,0 |
217 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Tools\script.xlb | - | 0,0 |
218 | C:\Program Files\OpenOffice.org 3\program\bootstrap.ini | - | 0,0 |
219 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\uno_packages\1D.tmp_\dict-es.oxt\META-INF\manifest.xml | - | 0,0 |
220 | 0 :\Program Files\OpenOffice.org 3\URE\bin\uno.ini | - | 0,0 |
221 | C:\Program Files\OpenOffice.org 3\Basis\share\basic\Gimmicks\dialog.xlb | - | 0,0 |
222 | C:\Program Files\OpenOffice.org 3\program\soffice.ini | - | 0,0 |
223 | C:\Program Files\OpenOffice.org 3\share\uno_packages\cache\registry\com.sun.star.comp.deployment.component.PackageRegistryBackend\unorc | - | 0,0 |
--- | Sum | - | 7045ms |
The next table provides an overview about the different data file types and their impact on startup performance.
Order | Extension/Type | Description | Size (byte) | Time (ms) |
---|---|---|---|---|
001 | RDB | Registry database for UNO types and services | ??? | 3.131ms |
002 | --- | Various NTFS system files/structures | ??? | 1.572ms |
003 | --- | Directory lookups/querying | ??? | 551ms |
004 | DAT | Configuration cache file | ??? | 498ms |
005 | RES | Resource Files | ??? | 353ms |
006 | ZIP | Compressed archive | ??? | 275ms |
007 | LM | Language file | ??? | 179ms |
008 | XML | UI configuration file | ??? | 82ms |
009 | DB | Configuration database | ??? | 69ms |
010 | TTF | TrueType Font | ??? | 67ms |
011 | XCU | Configuration XML data file | ??? | 57ms |
012 | HT | Help file | ??? | 42ms |
013 | INI | Low-level configuration file | ??? | 35ms |
014 | BMP | Bitmap file | ??? | 21ms |
015 | XLC | Basic Library | ??? | 19ms |
016 | XLB | Basic Library | ??? | 17ms |
017 | CONF | Unknown | 3.746 | 7ms |
018 | XBA | Basic Library | ??? | 0ms |
Process Monitor results - OpenOffice.org data warm startup
Process Monitor results - svdem.exe data cold startup
The following tables shows what data files (also NTFS system files) and paths are accessed/read during startup. The times are for total file I/O in descending order (only synchronous read operations are included).
Order | Path/File | Size (byte) | Time (ms) |
---|---|---|---|
002 | C:\Program Files\OpenOffice.org 3\Basis\program\applicat.rdb | - | 326 |
001 | C:\$Mft (Master File Table - NTFS system file) | - | 245 |
003 | C:\$Directory | - | 143 |
004 | C:\Program Files\OpenOffice.org 3\Basis\program\resource\vclen-US.res | - | 37 |
005 | C:\Windows\Fonts\tahoma.ttf | - | 17 |
006 | C:\Program Files\OpenOffice.org 3\program\resource | - | 14 |
007 | C:\Program Files\OpenOffice.org 3\Basis\program\resource | - | 5 |
008 | C:\Program Files\OpenOffice.org 3\program | - | 0,4 |
Total | --- | --- | 787ms |
Process Monitor results - svdem.exe data warm startup
The following tables shows what data files (also NTFS system files) and paths are accessed/read during startup. The times are for total file I/O in descending order (only synchronous read operations are included).
Order | Path/File | Size (byte) | Time (ms) |
---|---|---|---|
001 | C:\Program Files\OpenOffice.org 3 | - | 2,4 |
002 | C:\ | - | 0,83 |
003 | C:\Program Files\OpenOffice.org 3\Basis\program\resource | - | 0,77 |
005 | C:\Program Files\OpenOffice.org 3\BASIS-LINK | - | 0,75 |
006 | C:\Program Files\OpenOffice.org 3\program\FUNDAMENTAL.INI | - | 0,25 |
007 | C:\Windows\Prefetch\SVDEM.EXE-04B718DD.pf | - | 0,24 |
008 | C:\Program Files\OpenOffice.org 3\share\fonts\truetype\ | - | 0,18 |
009 | Other | - | 2,58 |
Total | --- | --- | 8ms |
Summary
Cold startup Writer (without AV real-time protection)
The following table summarises the measured values during OpenOffice.org Writer cold startup.
Aspect | Time | Percentage |
---|---|---|
Writer startup | 24800ms | 100 % |
Load OpenOffice.org libraries (file I/O) | 13012ms | 52,47 % |
Load Windows libraries (file I/O) | 242ms | 0,97 % |
Data file/path/system file access (file I/O) | 7045ms | 28,41 % |
CPU time (according to Process Monitor) | 2664ms | 10,74 % |
Query status/Open/Close files/folders | 305ms | 1,23% |
Registry access | 42ms | 0,17 % |
Write file access (file I/O) | 5ms | 0,02% |
Currently unknown | 1485ms | 5,99 % |
swriter.exe->soffice.exe->soffice.bin | 700ms | Additional time for startup (not included) |
The time spent on data file, paths and system file access is about half of library loading. Currently more than 80% of the cold startup time is spent on file access.
There is another aspect which has an impact on startup performance. If a user wants to start a Writer he/she normally selects the Writer symbol on the start menu. This action starts the swriter.exe executable, which starts soffice.exe with additional arguments, which starts a soffice.bin process with arguments. This startup procedure needs three processes to start a Writer. A quick lookup about the performance impact that this three process solutions has, reveals that about 700ms is spent to start the third process (soffice.bin) in the cold start scenario. It's obvious that we should make at least one process obsolete.
Warm startup Writer (without AV real-time protection)
The following table summaries the calculated values for OpenOffice.org warm startup. According to Process Monitor there were no read operations for OpenOffice.org or Windows libraries. Therefore Windows could map all necessary code/data from it's caches.
Aspect | Time | Percentage |
---|---|---|
Writer startup | 3800ms | 100 % |
Load OpenOffice.org libraries (file I/O) | 286ms | 7,53 % |
Load Windows libraries (file I/O) | 19ms | 0,50 % |
Data file/path/system file access (file I/O) | 279ms | 7,34 % |
Query status/Open/Close files/folders | 24ms | 0,63% |
CPU time (according to Process Monitor) | 2440ms | 64,21 % |
Registry access | 21ms | 0,55 % |
Write acess (file I/O) | 3ms | 0,08% |
Currently unknown | 728ms | 19,15 % |
swriter.exe->soffice.exe->soffice.bin | 200ms | Additional startup time (not included) |
Looking at the warm startup the picture completely changes. Now the startup time is mostely bound to the CPU. File and registry access have only a very minor impact, clearly below 20%.
Cold startup svdem.exe (without AV real-time protection)
The following table summarises the measured values during OpenOffice.org Writer cold startup.
Aspect | Time | Percentage |
---|---|---|
svdem.exe startup | 4010ms | 100 % |
Load OpenOffice.org libraries (file I/O) | 2715ms | 67,71 % |
Load Windows libraries (file I/O) | 181ms | 4,51 % |
Data file/path/system file access (file I/O) | 787ms | 19,63 % |
CPU time (according to Process Monitor) | 203ms | 5,06 % |
Query status/Open/Close files/folders | 10ms | 0,25% |
Registry access | 5ms | 0,12 % |
Write file access (file I/O) | 0ms | 0% |
Currently unknown | 109ms | 2,72 % |
The time spent on data file, paths and system file access is about one third of library loading. Currently about 87% of the cold start up time is spent on file access.
Warm startup svdem.exe (without AV real-time protection)
The following table summarises the measured values during OpenOffice.org svdem.exe warm startup.
Aspect | Time | Percentage |
---|---|---|
svdem.exe startup | 700ms | 100 % |
Load OpenOffice.org libraries (file I/O) | 27ms | 3,86% |
Load Windows libraries (file I/O) | 16ms | 2,29% |
Data file/path/system file access (file I/O) | 8ms | 1,14% |
CPU time (according to Process Monitor) | 204ms | 29,14 % |
Query status/Open/Close files/folders | 20ms | 1,29% |
Registry access | 7ms | 1,00 % |
Write file access (file I/O) | 0ms | 0% |
Currently unknown | 429ms | 61,29% |
[[Image:]]
How to tackle the poor start up performance
It's obvious that the poor start up performance is based on the fact that too much code/data is needed during start up. This results into the fact that too many library and data file parts are loaded into memory. For example looking at the Process Monitor log one can see that 5.022.720 bytes are read from the swmi.dll while the file itself has a total size of 7.332.352 bytes. That means that on Writer start up 68,5% of the file is loaded. One can ask why more than 2/3 of the Writer library must be loaded to just show an empty text document.
- Reorder the object files so start up code/data is packed to the start of the library. Code/data which is not needed should be put at the end. The operating system can better use caching on new page faults. One can clearly see that page faults on code which is far away from the last file access needs much more access time (see the following Process Monitor log which documents the first 20 synchronous paging requests for the Writer library).
Sq Time Duration Process Operation File Result Arguments -------------------------------------------------------------------------------------------------------------------------------------------------------------------- 0 10:39:57,8295310 0.0388471 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 0, Length: 32.768, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 1 10:39:57,8691117 0.0084098 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 6.910.464, Length: 1.536, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 2 10:39:57,8850302 0.0170215 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.836.800, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 3 10:39:57,9020634 0.0185521 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 4.767.744, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 4 10:39:57,9206244 0.0003079 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.865.472, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 5 10:39:58,1908649 0.0168220 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 6.000.640, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 6 10:39:59,0099537 0.0145339 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.922.816, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 7 10:39:59,1447624 0.0002975 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.906.432, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 8 10:39:59,2832993 0.0003109 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.890.048, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 9 10:39:59,2849484 0.0002171 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.881.856, Length: 8.192, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 10 10:39:59,2854035 0.0002645 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.853.184, Length: 12.288, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 11 10:39:59,2861022 0.0003106 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.939.200, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 12 10:39:59,2864368 0.0319449 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 4.784.128, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 13 10:39:59,3184339 0.0182722 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.984.256, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 14 10:39:59,3368399 0.0121761 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.967.872, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 15 10:39:59,3491563 0.0002791 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 5.955.584, Length: 12.288, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 16 10:39:59,3496231 0.0253999 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 6.053.888, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 17 10:39:59,3750942 0.0313613 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 6.037.504, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 18 10:39:59,4065809 0.0002794 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 6.021.120, Length: 16.384, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O 19 10:39:59,4069603 0.0003366 soffice.bin IRP_MJ_READ swmi.dll SUCCESS Offset: 6.017.024, Length: 4.096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O
- Reorder data in the UNO registry database files. One can again see that these files are read in random access pattern during start up. It would be much better if a reorder could convert this to sequential access pattern.
- It must be checked why a library is used on start up.
- This can have historical reasons which are not true anymore or specific parts of the library are needed.
- It's also possible to move code/data from one library to another one to decrease the number of libraries which necessary for start up.
- There is definitely code which is initialized although not needed on start up. Just to find those parts is not easy and obvious.
- Code must be changed to be usable for on-demand access.
- Consolidate code and libraries.
- Several different container classes
- Two string classes.
- Many helper classes spread over different libraries.
- Libraries for the same purpose (for example: sax.dll, fastsax.uno.dll, sax.uno.dll, libxml2.dll).
- OpenOffice.org uses about 10% of the start up time (cold start) to read file system specific data (e.g. C:\$Mft and C:\$Directory).
- One cause could be the high amount of files and folders which are accessed during start up ( ~100 libraries and more than 200 data files/pathes).
- The nesting of folders is also very high.
- Libraries and binaries are now spread over three different folders: OpenOffice.org/program, OpenOffice.org/Basis/program and OpenOfficer.org/URE/bin. The bad thing is that Windows uses a defined searching schema (at least one function starting from Windows XP SP1 can influence it, see SetDllDirectory()). That means that Windows first searches for OpenOffice.org libraries within folders which don't contain any. More information about this problem and how it degrades performance can be found here: http://msdn.microsoft.com/en-us/library/ms810432.aspx
- Look beside the executable.
- Look into the folder defined by "SetDllDirectory()".
- Look into the system folder, called "System32".
- Look into 16-bit system directory, called "System".
- Look into the Windows directory, normally called "Windows".
- Look into the directories that are listed in the PATH environment variable.
Random ideas
Some musings and ideas that may be good or may be rubbish - just to avoid losing them:
- get rid of calling soffice.exe from swriter.exe
- get rid of stlport (shaves off ~240 ms library load time)
- have platform dependent main function in soffice.bin that allows to do a lot of things before libraries are loaded (e.g. prefetching of libraries and files in threads)
- get rid of uwinapi.dll
- load i18n stuff on demand in sal or split up the library
- use ordinals for release builds again
- look for initialization code that can be executed in parallel