Roughly handles WPP events to avoid RegisteredTraceEventParser assertion

[wwh1004]

Before this pr, the unhandled WPP events will be cached in m_state.m_templates but can't be compared correctly.

[brianrob]

Can you share some details on the issue that you're looking to fix here? I am not super familiar with the details of the different ETW provider mechanisms, and so this will require some research.

[wwh1004]

In the following example which I use to analyze COM etw events, an assertion will be triggered because the TraceEventComparer does not correctly compare WPP events.

static void Main() {
	var session = new TraceEventSession("COMTrace");

	// For resolving process names
	session.EnableKernelProvider(KernelTraceEventParser.Keywords.Process);

	session.EnableProvider("Microsoft-Windows-COMRuntime");
	session.Source.Dynamic.AddCallbackForProviderEvent("Microsoft-Windows-COMRuntime", null, data => {
		var s = data.ToString();
		if (data.ProviderName == "Microsoft-Windows-COMRuntime" && data.ID == (TraceEventID)32769)
			return;
		if (data.PayloadByName("TargetProcessId") is int pid) {
			try {
				using var process = Process.GetProcessById(pid);
				s += " " + process.ProcessName;
			}
			catch {
			}
		}
		Console.WriteLine(data);
	});

	// WPP_ThisDir_CTLGUID_OLE32
	var ignoredClsids = File.ReadAllLines("IgnoredClsids.txt");
	session.EnableProvider(Guid.Parse("{bda92ae8-9f11-4d49-ba1d-a4c2abca692e}"));
	session.Source.UnhandledEvents += data => {
		var sb = new StringBuilder();
		foreach (byte b in data.EventData()) {
			if (!char.IsControl((char)b))
				sb.Append((char)b);
		}
		var s = sb.ToString();

		bool log;
		if (s.Contains("services.cxx"))
			log = true;
		else if (s.Contains("CComActivator::DoCreateInstance"))
			log = s.Contains("End CCI clsid:") && ignoredClsids.All(x => !s.Contains(x));
		else
			log = false;

		if (log) {
			Log.Information("Unhandled:" + Environment.NewLine +
				"{StringDump}" + Environment.NewLine +
				"{HexDump}", s, DumpByteArray(data.EventData()));
		}
	};
	session.Source.Process();
}

tdh!TdhGetEventInformation (rev):

inline BOOL HasExtEventSchemaTL(PEVENT_RECORD Event) {
    if (Event->ExtendedDataCount) {
        for (USHORT i = 0; i < Event->ExtendedDataCount; ++i) {
            if (Event->ExtendedData[i].ExtType == EVENT_HEADER_EXT_TYPE_EVENT_SCHEMA_TL) {
                return TRUE;
            }
        }
    }
    return FALSE;
}

TDHSTATUS TdhpGetTraceEventInfo(...) {
    BOOL IsClassic = Flags & EVENT_HEADER_FLAG_CLASSIC_HEADER;
    TDHSTATUS Status = IsClassic
        ? TdhpFindMatchClassFromWBEM(...) 
        : TdhpFindMatchProviderFromManifest(...);
}

TDHSTATUS TdhGetEventInformation(
    PEVENT_RECORD Event,
    ULONG TdhContextCount,
    PTDH_CONTEXT TdhContext,
    PTRACE_EVENT_INFO Buffer,
    PULONG BufferSize) {
    if ((Event->EventHeader.Flags & EVENT_HEADER_FLAG_TRACE_MESSAGE)) {
        // WPP Software Tracing events
        PSTRUCTUREDMESSAGE Message;
        if (!TdhpGetWPPCache(Event, TdhContextCount, TdhContext, &Message, ...)) {
	        // TMF file not found
            return ERROR_SUCCESS;
        }
        return TdhpGetTraceEventInfoFromStructMessage(Event, Message, Buffer, BufferSize);
    }
    else if ((Event->EventHeader.EventDescriptor.Channel == 11) || HasExtEventSchemaTL(Event)) {
        // TraceLogging-based events normally use channel 11.
        return TraceLogging::MetadataReader::TeiFromPayload(Buffer, *BufferSize, BufferSize, Event, ...);
    }
    else {
        // MOF-based and manifest-based events
        return TdhpGetTraceEventInfo(
            PointerSize,
            Event->EventHeader.Flags,
            &Event->EventHeader.ProviderId,
            &Event->EventHeader.EventDescriptor,
            Buffer,
            BufferSize);
    }
}

So we can check the EVENT_HEADER_FLAG_TRACE_MESSAGE flag to determine whether it is the WPP event.

When the tmf file is not passed to TdhGetEventInformation, for WPP events, the properties returned are invalid, although there are some values.

The returned properties is a representation of _STRUCTUREDMESSAGE, I don't know why Tdh returns these. I guess this might be an assumption made by Tdh.

https://github.com/selfrender/Windows-Server-2003/blob/5c6fe3db626b63a384230a1aa6b92ac416b0765f/sdktools/trace/traceprt/traceprt.h#L159...L179

Based on this situation, I believe that RegisteredTraceEventParser is unable to handle WPP events. Therefore, I add an attribute to determine whether a possible WPP event is present, and let RegisteredTraceEventParser::TryLookup return null for WPP events.

[wwh1004]

In TraceEventComparer, the priority of lookupAsWPP should be higher than lookupAsClassic, because the classic events contains WPP events. The changes about CloneToTemplate are some performance optimizations. For templates, I believe the eventRecord field can be omitted.

[wwh1004]

Fix double free caused by my CloneToTemplate optimization

[brianrob]

Thank you for the explanation. To make sure I'm understanding, are you saying that you're running into wpp events that aren't properly handled by TraceEvent and so they show up as UnhandledEvents?

[wwh1004]

I need to process some WPP events. I only need the raw WPP event records, and since I don't have a tmf file for parsing WPP events, I used UnhandledEvents. Although TraceEvent is correct from the final behavior, assertions are triggered internally. While troubleshooting the assertions, I found that RegisteredTraceEventParser was not correctly handling and caching WPP events, which also caused some performance issues. This PR fixes this part.