Share via


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

CELZONE_THREAD

Thread events, except for thread switch events, which are located in CELZONE_RESCHEDULE

CELZONE_PROCESS

Process events

CELZONE_RESCHEDULE

Scheduler and thread switch events

CELZONE_SYNCH

Synchronization events, including event, mutex, and semaphore operations, and calls to WaitForMultipleObjects

CELZONE_CRITSECT

Critical sections events

CELZONE_MIGRATE

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

Other Resources

Readlog Tool
CeLog Event Tracking