Welcome back for the second part of our two-part article series: Core Instrumentation Events in Windows 7. In the first article, we presented a high-level overview of the Event Tracing for Windows (ETW) technology and core OS instrumentation. We also discussed tool support to obtain and consume OS events. In this second part, we continue to provide more details about the events from various subcomponents in the core OS. We also explain how the different system events can be combined to produce a comprehensive picture of system behavior, which we demonstrate by using a set of Windows PowerShell scripts.
Disk, File, File Details and Driver Events
From a program's perspective, operations such as opening, reading, or writing files are the way to access the contents on the disk. Due to optimizations such as caching and prefetching, not all file IO requests result in immediate disk access. Furthermore, file contents may be scattered across disks, and certain disk devices support mirroring and striping, and so on. For such cases, reading one block of data from a file translates into multiple accesses to one or more disks. The events for file and disk access account for file IO start, file IO completion, disk access start, disk access end, split IO, driver activities and file (name to unique key) maps.
A request from a user application to access a file and the corresponding completion of that request back to the user application travels through a stack of multiple components. In the Windows IO system, IO operations are tracked by an entity called an IO Request Packet (IRP). A user-initiated IO operation is turned into an IRP when it enters the IO Manager. As an IRP traverses a chain of components, each component performs necessary tasks to process the request, updates the IRP and passes it on, if necessary, to the component that will handle the request next. When all requirements of the IO request are satisfied (in a simple case, a requested block of a file is retrieved from a disk), registered completion routines are called to perform any additional processing of the data, and the requested data is returned to the user application.
At a higher layer in the core IO system, File IO events record the operations issued by an application. File IO events include the following types: Create, Read, Write, Flush, Rename, Delete, Cleanup, Close, Set Information, Query Information, Directory Enumeration, and Directory Change Notification. Operations such as Create, Read, Write, Flush, Rename and Delete are straightforward, and they contain data items such as file key, IO request packet (IRP) pointer, block size, and offset into the file, as necessary. Set Information and Query Information events indicate that file attributes were set or queried. A Cleanup event is logged when the last handle to the file is closed. A Close event specifies that a file object is being freed. Directory Enumeration and Directory Change Notification events are logged when a directory is enumerated or a directory change notification is sent out to registered listeners, respectively. File IO events are logged to ETW when the operation is requested. Those that are interested in the completion and duration of the file IO operations can enable File IO Completion events, which can be correlated to the original File IO events through IRP pointer. File IO Completion events record IRP pointer and return status.
Disk events are logged at a lower level in the IO stack, and they contain disk-access-specific information. Read and Write operations generate Disk Read and Write events containing disk number, transfer size, byte offset to the address being accessed, IRP pointer, and response time of the access. Flush events record disk flush operations. Unlike File IO events that are logged at the beginning of operations, Disk IO events are logged at the IO completion time. Users have the option to collect additional Disk IO Init events for all Disk IO events (ReadInit, WriteInit and FlushInit events). As mentioned earlier, not all File IO events have matching Disk IO events, if for instance the requested content is already available in the cache or a write to disk operation is buffered. Split IO events indicate that IO requests have been split into multiple disk IO requests due to the underlying mirroring disk hardware. Users without such hardware will not see Split IO events even if they enable them. It maps the original parent IRP into multiple child IRPs.
Disk IO, File IO and Split IO events contain unique file keys created for open files. This file key can be used to track related IO operations within the IO system. However, the actual file name for the file operation is not available in any File or Disk IO events. To resolve the name of the files, File Details events are needed. All open files are enumerated to record their file keys and names. In a simulated state machine, file objects are tracked in terms of file keys, to record file IO requests and actual disk accesses, and then names are updated in the objects when File Details events are encountered. For a historical reason, File Keys in Disk IO and File Details events are named FileObject. Most File IO events contain both file object and file key.
Driver events indicate activities in drivers, which, depending on the device type, may or may not overlap with disk IO activities. Driver events may be of interest to users familiar with the Windows Driver Model (WDM). The driver instrumentation adds events around driver IO function calls and completion routines. Driver events contain driver data such as file key, IRP pointer, and routine addresses (major and minor function and completion routine), as appropriate for individual event types.
IO events usually result in a very large volume of events, which may require increasing the number and/or size of the buffers for the kernel session (-nb option in logman). Also, IO events are useful in analyzing file usages, disk access patterns and driver activities. However, the process and thread id values of the IO events, with the exception of Disk IO events, are not valid. To correlate these activities correctly to the originating thread and thus to the process, one needs to consider tracking Context Switch events.
Network Events
Network events are logged when network activities occur. Network events from the kernel session are emitted at TCP/IP and UDP/IP layers. TCP/IP events are logged when the following actions take place: Send, Receive, Disconnect, Retransmit, Reconnect, Copy, and Fail. They all contain the packet size, source and destination IP addresses and ports, except for Fail events since no such information is available. Also, the originating process id for Send type events and the target process id for Receive type events are included because often these network operations are not performed under the originating/receiving process context. This means that Network events can be attributed to a process, but not to a thread. UDP/IP events are either Send or Receive events, which include the data items listed above. Finally, each operation type (Send, Receive and so on) corresponds to a pair of events: one for IPV4 protocol and the other for IPV6. Events for IPV6 protocol were added in Windows Vista.
Registry Events
Most registry operations are instrumented with ETW, and these events can be attributed to processes and threads through process and thread ids in the event header. The Registry event payload does not contain a full registry key name. Instead, it includes a unique key, noted as Key Control Block (KCB), for each open registry key. At the end of a kernel session, rundown events are logged that map these keys to full registry names. To resolve registry names, one needs to use a similar technique utilized for file name resolution, in which these map events are used to update registry objects in the state machine. Registry events have been useful in analyzing access patterns and identifying redundant accesses for optimization. The Registry event payload contains the return status of the operation, which can be used to monitor registry operation failures and troubleshoot possible application problems.
Figure 1 Get-ETW-PID-List Script for Printing Process Table
}} else {
return $pidlist
}
}
}