Analyze CeLog Log Data (Compact 2013)
3/26/2014
This topic describes how to use the information in the Readlog output file to improve your system startup time.
Readlog Output File Format
The following Readlog output file (Bootlog.txt) shows a sample boot process for a device:
0:00:15.015.193 : nk.exe: Launching filesys.exe
0:00:15.106.055 : filesys.exe: Object store initialized
...
0:00:16.699.839 : filesys.exe: File system initialized
0:00:16.727.518 : filesys.exe: Launching CeLogFlush.exe
0:00:16.779.136 : filesys.exe: Launching shell.exe
0:00:17.091.626 : filesys.exe: Launching device.exe
0:00:18.038.225 : device.exe: Activating Drivers\BuiltIn
0:00:18.126.507 : device.exe: Activating Drivers\BuiltIn\notify
0:00:19.887.368 : device.exe: Activating Drivers\BuiltIn\WaveDev
0:00:19.960.906 : device.exe: Activating Drivers\BuiltIn\NDISUIO
0:00:19.986.069 : device.exe: Activating Drivers\BuiltIn\autoras
0:00:19.998.966 : device.exe: Activating Drivers\BuiltIn\NdisPower
0:00:20.011.025 : device.exe: Activating Drivers\BuiltIn\Ethman
...
0:00:20.115.738 : device.exe: Finished initializing
...
0:00:21.731.785 : filesys.exe: PSLs notified of system started
The log is displaying the following information:
- The time that the module or process began loading.
- The boot process that loaded the module or process.
- The name of the module or process that was loaded.
For example, at 18.038.225, the device.exe
process started loading the BuiltIn
driver:
0:00:18.038.225 : device.exe: Activating Drivers\BuiltIn\<driver module>
| | |_ Module being loaded/initialized
| |______________ Boot Process loading the module
|____________________________________ Timestamp that the module started loading
Identify Potential Startup Problems
Use the information in the startup log to analyze the load time for each module and identify problems in the startup sequence.
Important
You can load the .clg file directly into the Remote Kernel Tracker tool to view thread-level information such as thread priority issues, when threads block waiting on events, and which component signals the blocking events. By showing information such as system activity and module and component dependencies, Kernel Tracker provides a more complete picture of startup time issues than what you see by using only the timestamps in the processed log file. For more information, see Remote Timeline Viewer.
After you identify latencies in the boot sequence, use the log to verify that modules load in the correct sequence to support operation dependencies. If you identify a problem, you can use the Device Manager (Device.exe) registry to set the dependent driver to load at the correct step of the boot sequence.
For example, the preceding sample log shows that the \BuiltIn\notify
driver starts loading at 0:00:18.126.507 and that the following driver begins loading at 0:00:19.887.368. Compared to the other drivers, the notify driver takes significantly longer to load. If the notify driver has a dependency on the Ethman driver, which loads later, this dependency might be the cause of the notify driver loading delay.
You can set the Order sub-key in the HKEY_LOCAL_MACHINE\Drivers\BuiltIn\Ethman and the HKEY_LOCAL_MACHINE\Drivers\BuiltIn\notify registry entries to ensure that the Ethman driver loads before the notify driver.
Note
Depending on your system architecture, you may be able to use other methods to enforce the boot sequence. For more information about Device Manager, see Device Manager.
Expand Logging Zones for More Detailed Analysis
You can use logging zones to perform deeper startup time analysis.
After you generate the initial log that provides details about boot events and sequence, expand CeLog zones captured at boot time to further analyze boot time performance. The following table describes the zones relevant to boot time that CeLog supports and the events that each zone tracks:
Zone |
Types of events tracked |
---|---|
|
Thread events, except for thread switch events, which are located in |
|
Process events |
|
Scheduler and thread switch events |
|
Synchronization events, including event, mutex, and semaphore operations, and calls to WaitForMultipleObjects |
|
Critical sections events |
|
Events for migration of threads between processes |
For more information about the CeLog zones, see CeLog Zones.
See Also
Concepts
Analyze Startup Time with CeLog