DTrace ETW

Use DTrace for Windows to process existing ETW events and to add new ETW events.

Event Tracing for Windows (ETW) is a kernel-level tracing facility that lets you log kernel or application-defined events to a log file. You can consume the events in real time or from a log file and use them to debug an application or to determine where performance issues are occurring in the application. For general information about ETW, see About Event Tracing.

Note

DTrace is supported in the Insider builds of Windows after version 18980 and Windows Server Build 18975.

For general information about working with DTrace on Windows, see DTrace.

ETW Windows DTrace Provider

You can use DTrace to capture and report trace logged and manifest based ETW events. To probe specific keywords/levels/eventIDs, ETW probes will work much more reliably if you don’t use wild cards. Instead fully specify your probe based on these rules:

Probename = etw

Modname = Provider guid in the form xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, using all lowercase characters.

Funcname = Level_Keyword of the form 0x00_0x0000000000000000. To match everything this should be set to 0xff_0xffffffffffffffff.

Probename = Integer Event ID or "generic_event" to match all event IDs.

Filtering based on Probename only works for manifested events. Use wild-card (*) for tracelogged events.

The ETW payload is accessed via arg0. This is made up of nt`_EVENT_HEADER followed by event specific date.

Determining available ETW providers

Use the logman command to display active ETW providers and their Provider GUIDs.

C:\>logman query providers
...
Microsoft-Windows-Kernel-Memory {D1D93EF7-E1F2-4F45-9943-03D245FE6C00}
Microsoft-Windows-Kernel-Network {7DD42A49-5329-4832-8DFD-43D979153A88}
Microsoft-Windows-Kernel-PnP {9C205A39-1250-487D-ABD7-E831C6290539}
Microsoft-Windows-Kernel-Power {331C3B3A-2005-44C2-AC5E-77220C37D6B4}
Microsoft-Windows-Kernel-Prefetch {5322D61A-9EFA-4BC3-A3F9-14BE95C144F8}
Microsoft-Windows-Kernel-Process {22FB2CD6-0E7B-422B-A0C7-2FAD1FD0E716}
...

Displaying existing ETW provider information

DTrace has the capability to output ETW events. This is helpful for scenarios where there is existing ETW pipeline to report, collect and analyze.

Use this example DTrace command to report Microsoft-Windows-Kernel-Memory provider events.

C:\>dtrace -n "etw:d1d93ef7-e1f2-4f45-9943-03d245fe6c00:0xff_0xffffffffffffffff:12"
dtrace: description 'etw:d1d93ef7-e1f2-4f45-9943-03d245fe6c00:0xff_0xffffffffffffffff:12' matched 1 probe
CPU     ID                    FUNCTION:NAME
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12
  0   3271       0xff_0xffffffffffffffff:12

Adding new ETW events

Etw trace events can be created by calling the etw_trace macro. Events will only be logged if there is an active listener for the specified trace provider, otherwise they'll be skipped.

The etw_trace macro supports basic datatypes such as int8, uint8, int16, uint16, int32, uint32, int64, uint64, hexint32, hexint64 and string. See the Supported ETW data types table below for more details.

Example ETW_TRACE macro:

This script generates a custom ETW event when the syscall routine returns 0xc0000001 - STATUS_UNSUCCESSFUL.

You can change the this->status value to use a different NTSTATUS values to log different syscall return values.

syscall:::return 
{ 
	this->status = (uint32_t) arg0;

	if (this->status == 0xc0000001UL) 
	{ 
		etw_trace
		(
    		"Tools.DTrace.Platform", /* Provider Name */
   	 		"AAD330CC-4BB9-588A-B252-08276853AF02", /* Provider GUID */
    		"My custom event from DTrace", /* Event Name */
    		1, /* Event Level (0 - 5) */
    		0x0000000000000020, /* Flag */
    		"etw_int32", /* Field_1 Name */
    		"PID",/* Field_1 Type */
     		(int32_t)pid, /* Field_1 Value  */
     		"etw_string", /* Field_2 Name */
     		"Execname", /* Field_2 type */
      		execname, /* Field_2 Value */
     		"etw_string", /* Field_3 Name */
     		"Probefunc", /* Field_3 type */
      		probefunc /* Field_3 Value */   
			);
	}
}

C:\> dtrace -s addnewetwevent.d
dtrace: script 'addnewetwevent.d' matched 1881 probes
CPU     ID                    FUNCTION:NAME
  0     93 NtAlpcSendWaitReceivePort:return
  0     93 NtAlpcSendWaitReceivePort:return
  0     93 NtAlpcSendWaitReceivePort:return

ETW NUMA MEM STATS example code

This example script uses Microsoft-Windows-Kernel-Memory ETW provider to dump NUMA node memory. Page size can be converted to size in KB by multiplying by 4. For general information on NUMA see NUMA Support.

This code is also located at https://github.com/microsoft/DTrace-on-Windows/blob/windows/samples/windows/etw/numamemstats.d

typedef struct KernelMemInfoEvent
{
        struct nt`_EVENT_HEADER _EH;
	uint32_t PartitionId;
	uint32_t Count;
	uint32_t NodeNumber;
}kmi;

typedef struct MemoryNodeInfo
{
	uint64_t TotalPageCount;
	uint64_t SmallFreePageCount;
	uint64_t SmallZeroPageCount;
	uint64_t MediumFreePageCount;
	uint64_t MediumZeroPageCount;
	uint64_t LargeFreePageCount;
	uint64_t LargeZeroPageCount;
	uint64_t HugeFreePageCount;
	uint64_t HugeZeroPageCount;
}m_nodeinfo;

int printcounter;

BEGIN
{
	printcounter = 0;
}

/* MemNodeInfo */
etw:d1d93ef7-e1f2-4f45-9943-03d245fe6c00:0xff_0xffffffffffffffff:12
{
	if (printcounter%10 == 0)
	{
		printf ("\n \n");
		printf("Partition ID: %d \n",((kmi *)arg0)->PartitionId);
		printf("Count: %d \n", ((kmi *)arg0)->Count);
		
		printf("Node number: %d\n", ((kmi *)arg0)->NodeNumber);
		counters = (m_nodeinfo*)(arg0 + sizeof(struct nt`_EVENT_HEADER) + 12);
		print(*counters);

		/* Dump rest of the NUMA node info */

		if (((kmi *)arg0)->Count > 1)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(1)) + (sizeof(uint32_t)*(1)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(1)) + (sizeof(uint32_t)*(1)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 2)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(2)) + (sizeof(uint32_t)*(2)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(2)) + (sizeof(uint32_t)*(2)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 3)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(3)) + (sizeof(uint32_t)*(3)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(3)) + (sizeof(uint32_t)*(3)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 4)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(4)) + (sizeof(uint32_t)*(4)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(4)) + (sizeof(uint32_t)*(4)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 5)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(5)) + (sizeof(uint32_t)*(5)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(5)) + (sizeof(uint32_t)*(5)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 6)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(6)) + (sizeof(uint32_t)*(6)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(6)) + (sizeof(uint32_t)*(6)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 7)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(7)) + (sizeof(uint32_t)*(7)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(7)) + (sizeof(uint32_t)*(7)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 8)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(8)) + (sizeof(uint32_t)*(8)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(8)) + (sizeof(uint32_t)*(8)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 9)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(9)) + (sizeof(uint32_t)*(9)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(9)) + (sizeof(uint32_t)*(9)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 10)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(10)) + (sizeof(uint32_t)*(10)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(10)) + (sizeof(uint32_t)*(10)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 11)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(11)) + (sizeof(uint32_t)*(11)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(11)) + (sizeof(uint32_t)*(11)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 12)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(12)) + (sizeof(uint32_t)*(12)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(12)) + (sizeof(uint32_t)*(12)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 13)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(13)) + (sizeof(uint32_t)*(13)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(13)) + (sizeof(uint32_t)*(13)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 14)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(14)) + (sizeof(uint32_t)*(14)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(14)) + (sizeof(uint32_t)*(14)) + sizeof(uint32_t));
			print(*counters);
		}
		if (((kmi *)arg0)->Count > 15)
		{
			nodenumber = (uint32_t *) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(15)) + (sizeof(uint32_t)*(15)) );
			printf ("Node Number: %d \n", *nodenumber);
			counters = (m_nodeinfo*) (arg0 + sizeof(struct nt`_EVENT_HEADER) + 8 + (sizeof(m_nodeinfo)*(15)) + (sizeof(uint32_t)*(15)) + sizeof(uint32_t));
			print(*counters);
		}

	}
	exit(1);
	printcounter++;
}

Save the file as etwnumamemstats.d

Open a command prompt as an Administrator and run the script using the -s option.

Running on a client Windows PC, a single NUMA node is displayed.

C:\> dtrace -s etwnumamemstats.d
trace: script 'etwnumamemstats.d' matched 36 probes
CPU     ID                    FUNCTION:NAME
  0  42735       0xff_0xffffffffffffffff:12

Partition ID: 0
Count: 1
Node number: 1
m_nodeinfo {
    uint64_t TotalPageCount = 0xab98d
    uint64_t SmallFreePageCount = 0
    uint64_t SmallZeroPageCount = 0x1bec
    uint64_t MediumFreePageCount = 0
    uint64_t MediumZeroPageCount = 0x5a
    uint64_t LargeFreePageCount = 0
    uint64_t LargeZeroPageCount = 0
    uint64_t HugeFreePageCount = 0
    uint64_t HugeZeroPageCount = 0
}
  0  42735       0xff_0xffffffffffffffff:12

Supported ETW data types

ETW type	D Language data type	Notes
etw_struct	Integer	The payload value of this type represents the count of member a new structure will have.
etw_string	string	N/A
etw_mbcsstring	string	N/A
etw_int8	Integer	Type size should match, and casting to `int8_t` in the D script is advised
etw_uint8	Integer	Type size should match, and casting to `uint8_t` in the D script is advised
etw_int16	Integer	Type size should match, and casting to `int16_t` in the D script is advised
etw_uint16	Integer	Type size should match, and casting to `uint16_t` in the D script is advised
etw_int32	Integer	N/A
etw_uint32	Integer	N/A
etw_int64	Integer	Type must be explicitly be `int64_t` since D defaults to `int32_t`
etw_uint64	Integer	Type must be explicitly be `int64_t` since D defaults to `int32_t`
etw_float	Scalar	Floating-point constants are not allowed in D script, but does allow it on loaded symbols
etw_double	Scalar	Floating-point constants are not allowed in D script, but does allow it on loaded symbols
etw_bool32	Integer	N/A
etw_hexint32	Integer	N/A
etw_hexint64	Integer	Type must be explicitly be `int64_t` since D defaults to `int32_t`
etw_countedmbcsstring	Integer	N/A
etw_intptr	Integer	The data type size changes according to the architecture (`int32_t` vs `int64_t`)
etw_uintptr	Integer	The data type size changes according to the architecture (`int32_t` vs `int64_t`)
etw_pointer	Integer	The data type size changes according to the architecture (`int32_t` vs `int64_t`)
etw_char16	Integer	Type size should match, and casting to `int16_t` in the D script is advised
etw_char8	Integer	Type size should match, and casting to `int8_t` in the D script is advised
etw_bool8	Integer	Type size should match, and casting to `int8_t` in the D script is advised
etw_hexint8	Integer	Type size should match, and casting to `int8_t` in the D script is advised
etw_hexint16	Integer	Type size should match, and casting to `int16_t` in the D script is advised
etw_pid	Integer	N/A
etw_tid	Integer	N/A
etw_mbcsxml	Integer	N/A
etw_mbcsjson	Integer	N/A
etw_countedmbcsxml	Integer	N/A
etw_countedmbcsjson	Integer	N/A
etw_win32error	Integer	N/A
etw_ntstatus	Integer	N/A
etw_hresult	Integer	N/A

See Also

DTrace on Windows

DTrace Windows Programming

DTrace Windows Code Samples

DTrace Live Dump