private void Reset()
{
if (!CanReset)
{
throw new InvalidOperationException("Event stream is not resetable (e.g. real time).");
}
for (int i = 0; i < handles.Length; i++)
{
if (handles[i] != TraceEventNativeMethods.INVALID_HANDLE_VALUE)
{
TraceEventNativeMethods.CloseTrace(handles[i]);
handles[i] = TraceEventNativeMethods.INVALID_HANDLE_VALUE;
}
// Annoying. The OS resets the LogFileMode field, so I have to set it up again.
if (!useClassicETW)
{
logFiles[i].LogFileMode = TraceEventNativeMethods.PROCESS_TRACE_MODE_EVENT_RECORD;
logFiles[i].LogFileMode |= TraceEventNativeMethods.PROCESS_TRACE_MODE_RAW_TIMESTAMP;
}
handles[i] = TraceEventNativeMethods.OpenTrace(ref logFiles[i]);
if (handles[i] == TraceEventNativeMethods.INVALID_HANDLE_VALUE)
{
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRForLastWin32Error());
}
}
}
public bool InitSymbolResolver(SymbolResolverContextInfo context)
{
symbolReader = new DefaultSymbolReader(context);
contextInfo = context;
TraceEventNativeMethods.SymSetOptions(
TraceEventNativeMethods.SymOptions.SYMOPT_DEBUG |
TraceEventNativeMethods.SymOptions.SYMOPT_CASE_INSENSITIVE |
// TraceEventNativeMethods.SymOptions.SYMOPT_DEFERRED_LOADS |
//TraceEventNativeMethods.SymOptions.SYMOPT_LOAD_LINES |
TraceEventNativeMethods.SymOptions.SYMOPT_EXACT_SYMBOLS |
TraceEventNativeMethods.SymOptions.SYMOPT_UNDNAME // undecorated names
);
// for testing purpose
Environment.SetEnvironmentVariable("_NT_SYMBOL_PATH", @"SRV*c:\websymbols*http://msdl.microsoft.com/download/symbols");
bool bInit = TraceEventNativeMethods.SymInitializeW(contextInfo.currentProcessHandle, null, false);
if (bInit)
{
registerCallback = new TraceEventNativeMethods.SymRegisterCallbackProc(SymRegisterCallbackProcInfo);
TraceEventNativeMethods.SymRegisterCallbackW64(contextInfo.currentProcessHandle, registerCallback, 0);
}
return(bInit);
}
public EventPipeEventSourceV1(Deserializer deserializer, string fileName, int version)
: base(deserializer)
{
// V1 EventPipe doesn't have process info.
// Since it's from a single process, use the file name as the process name.
_processName = Path.GetFileNameWithoutExtension(fileName);
_processId = 0;
_version = version;
// V1 EventPipe doesn't have osVersion, cpuSpeedMHz, pointerSize, numberOfProcessors
osVersion = new Version("0.0.0.0");
cpuSpeedMHz = 10;
pointerSize = 8; // V1 EventPipe only supports Linux which is x64 only.
numberOfProcessors = 1;
// We need to read the header to get the sync time information here
ReadEventPipeTimeInfo();
IntPtr mem = Marshal.AllocHGlobal(sizeof(TraceEventNativeMethods.EVENT_RECORD));
TraceEventNativeMethods.ZeroMemory(mem, sizeof(TraceEventNativeMethods.EVENT_RECORD));
_header = (TraceEventNativeMethods.EVENT_RECORD *)mem;
_eventParser = new EventPipeTraceEventParser(this);
}
private void symbolParser_DbgIDRSDSTraceData(DbgIDRSDSData obj)
{
string pdbFile = obj.PdbFileName;
Guid pdbGuid = obj.GuidSig;
if (!symbolFiles.ContainsKey(pdbFile))
{
// unsafe, but OK to do for now,
// other options is to Marshal.AllocHGlobal.
// other option is to use fixed in unsafe code
// other option ....?1
GCHandle handle = GCHandle.Alloc(pdbGuid, GCHandleType.Pinned);
IntPtr guidPtr = handle.AddrOfPinnedObject();
//
StringBuilder pdbFullPath = new StringBuilder(1024);
// Try To locate the symbol file.
//tmm.pdbWith Guid2d244915-4bd6-4d74-a496-8877396f5510
bool foundPDB = TraceEventNativeMethods.SymFindFileInPathW(contextInfo.currentProcessHandle,
null,
pdbFile,
guidPtr,
(int)obj.Age,
0,
TraceEventNativeMethods.SSRVOPT_GUIDPTR,
pdbFullPath,
null,
IntPtr.Zero);
int lastError = Marshal.GetLastWin32Error();
if (lastError == 0x2) // path not found
{
Console.WriteLine("Can't find symbol for " + pdbFile);
Console.WriteLine("are you sure _NT_SYMBOL_PATH is set?"); // check if _NT_SYMBOL_PATH is set
}
if (foundPDB)
{
PDBInfo info = new PDBInfo()
{
pdbFullPath = pdbFullPath.ToString(), pdbImageBase = (ulong)obj.ImageBase
};
symbolFiles.Add(pdbFile, info);
}
else
{
symbolFiles.Add(pdbFile, null);
}
handle.Free();
}
}
public override bool Process()
{
if (processTraceCalled)
{
Reset();
}
processTraceCalled = true;
stopProcessing = false;
int dwErr = TraceEventNativeMethods.ProcessTrace(handles, (uint)handles.Length, (IntPtr)0, (IntPtr)0);
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRFromWin32(dwErr));
return(!stopProcessing);
}
protected override void Dispose(bool disposing)
{
if (handles != null)
{
foreach (ulong handle in handles)
{
if (handle != TraceEventNativeMethods.INVALID_HANDLE_VALUE)
{
TraceEventNativeMethods.CloseTrace(handle);
}
}
handles = null;
}
base.Dispose(disposing);
GC.SuppressFinalize(this);
}
public unsafe ulong LoadSymModule(string moduleName, ulong moduleBase)
{
// given a module file name *.exe or .dll, we will try to find a matching .PDB symbol and load it.
Console.WriteLine("Trying to load symbol for file" + moduleName);
// lookup the image name
string moduleFileName = System.IO.Path.GetFileName(moduleName);
string pdbFileName = System.IO.Path.ChangeExtension(moduleFileName, ".pdb");
if (symbolFiles.ContainsKey(pdbFileName))
{
PDBInfo info = symbolFiles[pdbFileName];
if (info != null)
{
return(TraceEventNativeMethods.SymLoadModuleExW(contextInfo.currentProcessHandle,
IntPtr.Zero, info.pdbFullPath, null, info.pdbImageBase, (uint)0x10000000, null, (uint)0));
}
}
return(0);
}
private void Reset()
{
if (!CanReset)
{
throw new InvalidOperationException("Event stream is not resetable (eg Real time)");
}
// Annoying. The OS resets the LogFileMode field, so I have to set it up again.
if (!useClassicETW)
{
primaryLogFile.LogFileMode = TraceEventNativeMethods.PROCESS_TRACE_MODE_EVENT_RECORD;
}
if (handles.Length > 1)
{
if (handles[1] != TraceEventNativeMethods.INVALID_HANDLE_VALUE)
{
TraceEventNativeMethods.CloseTrace(handles[1]);
}
kernelModeLogFile.LogFileMode = primaryLogFile.LogFileMode;
handles[1] = TraceEventNativeMethods.OpenTrace(ref kernelModeLogFile);
if (TraceEventNativeMethods.INVALID_HANDLE_VALUE == handles[1])
{
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRForLastWin32Error());
}
}
if (handles[0] != TraceEventNativeMethods.INVALID_HANDLE_VALUE)
{
TraceEventNativeMethods.CloseTrace(handles[0]);
}
handles[0] = TraceEventNativeMethods.OpenTrace(ref primaryLogFile);
if (TraceEventNativeMethods.INVALID_HANDLE_VALUE == handles[0])
{
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRForLastWin32Error());
}
}
// Process is called after all desired subscriptions have been registered.
/// <summary>
/// Processes all the events in the data soruce, issuing callbacks that were subscribed to. See
/// code:#Introduction for more
/// </summary>
/// <returns>false If StopProcesing was called</returns>
// [SecuritySafeCritical]
public override bool Process()
{
if (processTraceCalled)
{
Reset();
}
processTraceCalled = true;
stopProcessing = false;
int dwErr = TraceEventNativeMethods.ProcessTrace(handles, (uint)handles.Length, (IntPtr)0, (IntPtr)0);
if (dwErr == 6)
{
throw new ApplicationException("Error opening ETL file. Most likely caused by opening a Win8 Trace on a Pre Win8 OS.");
}
// ETW returns 1223 when you stop processing explicitly
if (!(dwErr == 1223 && stopProcessing))
{
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRFromWin32(dwErr));
}
return(!stopProcessing);
}
public ETWTraceEventSource(string fileOrSessionName, TraceEventSourceType type)
{
long now = DateTime.Now.ToFileTime() - 100000; // subtract 10ms to avoid negative times.
primaryLogFile = new TraceEventNativeMethods.EVENT_TRACE_LOGFILEW();
primaryLogFile.BufferCallback = this.TraceEventBufferCallback;
useClassicETW = Environment.OSVersion.Version.Major < 6;
if (useClassicETW)
{
IntPtr mem = TraceEventNativeMethods.AllocHGlobal(sizeof(TraceEventNativeMethods.EVENT_RECORD));
TraceEventNativeMethods.ZeroMemory(mem, (uint)sizeof(TraceEventNativeMethods.EVENT_RECORD));
convertedHeader = (TraceEventNativeMethods.EVENT_RECORD *)mem;
primaryLogFile.EventCallback = RawDispatchClassic;
}
else
{
primaryLogFile.LogFileMode = TraceEventNativeMethods.PROCESS_TRACE_MODE_EVENT_RECORD;
primaryLogFile.EventCallback = RawDispatch;
}
if (type == TraceEventSourceType.Session)
{
primaryLogFile.LoggerName = fileOrSessionName;
primaryLogFile.LogFileMode |= TraceEventNativeMethods.EVENT_TRACE_REAL_TIME_MODE;
}
else
{
if (type == TraceEventSourceType.UserAndKernelFile)
{
// See if we have also have kernel log moduleFile.
if (fileOrSessionName.Length > 4 && string.Compare(fileOrSessionName, fileOrSessionName.Length - 4, ".etl", 0, 4, StringComparison.OrdinalIgnoreCase) == 0)
{
string kernelFileName = fileOrSessionName.Substring(0, fileOrSessionName.Length - 4) + ".kernel.etl";
if (File.Exists(kernelFileName))
{
if (File.Exists(fileOrSessionName))
{
handles = new ulong[2];
handles[0] = TraceEventNativeMethods.INVALID_HANDLE_VALUE;
kernelModeLogFile = new TraceEventNativeMethods.EVENT_TRACE_LOGFILEW();
kernelModeLogFile.BufferCallback = primaryLogFile.BufferCallback;
kernelModeLogFile.EventCallback = primaryLogFile.EventCallback;
kernelModeLogFile.LogFileName = kernelFileName;
kernelModeLogFile.LogFileMode = primaryLogFile.LogFileMode;
handles[1] = TraceEventNativeMethods.OpenTrace(ref kernelModeLogFile);
if (TraceEventNativeMethods.INVALID_HANDLE_VALUE == handles[1])
{
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRForLastWin32Error());
}
}
else
{
// we have ONLY a *.kernel.etl moduleFile, treat it as the primary moduleFile.
fileOrSessionName = kernelFileName;
}
}
}
if (!File.Exists(fileOrSessionName))
{
throw new FileNotFoundException("Unable to find the file " + fileOrSessionName);
}
}
primaryLogFile.LogFileName = fileOrSessionName;
}
// Open the main data source
if (handles == null)
{
handles = new ulong[1];
}
handles[0] = TraceEventNativeMethods.OpenTrace(ref primaryLogFile);
if (TraceEventNativeMethods.INVALID_HANDLE_VALUE == handles[0])
{
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRForLastWin32Error());
}
// Session offset time is the minimum of all times.
sessionStartTime100ns = primaryLogFile.LogfileHeader.StartTime;
if (handles.Length == 2 && kernelModeLogFile.LogfileHeader.StartTime < sessionStartTime100ns)
{
sessionStartTime100ns = kernelModeLogFile.LogfileHeader.StartTime;
}
// Real time providers don't set this to something useful
if (sessionStartTime100ns == 0)
{
sessionStartTime100ns = now;
}
sessionEndTime100ns = primaryLogFile.LogfileHeader.EndTime;
if (handles.Length == 2 && sessionEndTime100ns < kernelModeLogFile.LogfileHeader.EndTime)
{
sessionEndTime100ns = kernelModeLogFile.LogfileHeader.EndTime;
}
if (sessionEndTime100ns == 0)
{
sessionEndTime100ns = sessionStartTime100ns;
}
pointerSize = (int)primaryLogFile.LogfileHeader.PointerSize;
if (handles.Length == 2)
{
pointerSize = (int)kernelModeLogFile.LogfileHeader.PointerSize;
}
if (pointerSize == 0)
{
pointerSize = sizeof(IntPtr);
Debug.Assert((primaryLogFile.LogFileMode & TraceEventNativeMethods.EVENT_TRACE_REAL_TIME_MODE) != 0);
}
Debug.Assert(pointerSize == 4 || pointerSize == 8);
eventsLost = (int)primaryLogFile.LogfileHeader.EventsLost;
cpuSpeedMHz = (int)primaryLogFile.LogfileHeader.CpuSpeedInMHz;
numberOfProcessors = (int)primaryLogFile.LogfileHeader.NumberOfProcessors;
// Logic for looking up process names
processNameForID = new Dictionary <int, string>();
Kernel.ProcessStartGroup += delegate(ProcessTraceData data) {
// Get just the file name without the extension. Can't use the 'Path' class because
// it tests to make certain it does not have illegal chars etc. Since KernelImageFileName
// is not a true user mode path, we can get failures.
string path = data.KernelImageFileName;
int startIdx = path.LastIndexOf('\\');
if (0 <= startIdx)
{
startIdx++;
}
else
{
startIdx = 0;
}
int endIdx = path.LastIndexOf('.', startIdx);
if (endIdx < 0)
{
endIdx = path.Length;
}
processNameForID[data.ProcessID] = path.Substring(startIdx, endIdx - startIdx);
};
}
private unsafe string GetXml()
{
int uncompressedSize = GetInt32At(4);
if (0x10000 <= uncompressedSize)
{
return("");
}
byte[] uncompressedData = new byte[uncompressedSize];
fixed(byte *uncompressedPtr = uncompressedData)
{
byte *compressedData = ((byte *)DataStart) + 8; // Skip header (State + UncompressedLength)
int compressedSize = EventDataLength - 8; // Compressed size is total size minus header.
int resultSize = 0;
int hr = TraceEventNativeMethods.RtlDecompressBuffer(
TraceEventNativeMethods.COMPRESSION_FORMAT_LZNT1 | TraceEventNativeMethods.COMPRESSION_ENGINE_MAXIMUM,
uncompressedPtr,
uncompressedSize,
compressedData,
compressedSize,
out resultSize);
if (hr == 0 && resultSize == uncompressedSize)
{
var indent = 0;
// PrettyPrint the XML
char * charPtr = (Char *)uncompressedPtr;
StringBuilder sb = new StringBuilder();
char * charEnd = &charPtr[uncompressedSize / 2];
bool noChildren = true;
while (charPtr < charEnd)
{
char c = *charPtr;
if (c == 0)
{
break; // we will assume null termination
}
if (c == '<')
{
var c1 = charPtr[1];
bool newLine = false;
if (c1 == '/')
{
newLine = !noChildren;
noChildren = false;
}
else if (Char.IsLetter(c1))
{
noChildren = true;
newLine = true;
indent++;
}
if (newLine)
{
sb.AppendLine();
for (int i = 0; i < indent; i++)
{
sb.Append(' ');
}
}
if (c1 == '/')
{
--indent;
}
}
sb.Append(c);
charPtr++;
}
return(sb.ToString());
}
}
return("");
}
/// <summary>
/// Open a ETW event source for processing. This can either be a moduleFile or a real time ETW session
/// </summary>
/// <param name="fileOrSessionName">
/// If type == ModuleFile this is the name of the moduleFile to open.
/// If type == Session this is the name of real time sessing to open.</param>
/// <param name="type"></param>
// [SecuritySafeCritical]
public ETWTraceEventSource(string fileOrSessionName, TraceEventSourceType type)
{
long now = DateTime.Now.ToFileTime() - 100000; // used as the start time for real time sessions (sub 10msec to avoid negative times)
// Allocate the LOGFILE and structures and arrays that hold them
// Figure out how many log files we have
if (type == TraceEventSourceType.MergeAll)
{
string fileBaseName = Path.GetFileNameWithoutExtension(fileOrSessionName);
string dir = Path.GetDirectoryName(fileOrSessionName);
if (dir.Length == 0)
{
dir = ".";
}
List <string> allLogFiles = new List <string>();
allLogFiles.AddRange(Directory.GetFiles(dir, fileBaseName + ".etl"));
allLogFiles.AddRange(Directory.GetFiles(dir, fileBaseName + ".kernel.etl"));
allLogFiles.AddRange(Directory.GetFiles(dir, fileBaseName + ".clr*.etl"));
allLogFiles.AddRange(Directory.GetFiles(dir, fileBaseName + ".user*.etl"));
if (allLogFiles.Count == 0)
{
throw new FileNotFoundException("Could not find file " + fileOrSessionName);
}
logFiles = new TraceEventNativeMethods.EVENT_TRACE_LOGFILEW[allLogFiles.Count];
for (int i = 0; i < allLogFiles.Count; i++)
{
logFiles[i].LogFileName = allLogFiles[i];
}
}
else
{
logFiles = new TraceEventNativeMethods.EVENT_TRACE_LOGFILEW[1];
if (type == TraceEventSourceType.FileOnly)
{
logFiles[0].LogFileName = fileOrSessionName;
}
else
{
Debug.Assert(type == TraceEventSourceType.Session);
logFiles[0].LoggerName = fileOrSessionName;
logFiles[0].LogFileMode |= TraceEventNativeMethods.EVENT_TRACE_REAL_TIME_MODE;
}
}
handles = new ulong[logFiles.Length];
// Fill out the first log file information (we will clone it later if we have mulitple files).
logFiles[0].BufferCallback = this.TraceEventBufferCallback;
handles[0] = TraceEventNativeMethods.INVALID_HANDLE_VALUE;
useClassicETW = Environment.OSVersion.Version.Major < 6;
if (useClassicETW)
{
IntPtr mem = Marshal.AllocHGlobal(sizeof(TraceEventNativeMethods.EVENT_RECORD));
TraceEventNativeMethods.ZeroMemory(mem, (uint)sizeof(TraceEventNativeMethods.EVENT_RECORD));
convertedHeader = (TraceEventNativeMethods.EVENT_RECORD *)mem;
logFiles[0].EventCallback = RawDispatchClassic;
}
else
{
logFiles[0].LogFileMode |= TraceEventNativeMethods.PROCESS_TRACE_MODE_EVENT_RECORD;
logFiles[0].EventCallback = RawDispatch;
}
// We want the raw timestamp because it is needed to match up stacks with the event they go with.
logFiles[0].LogFileMode |= TraceEventNativeMethods.PROCESS_TRACE_MODE_RAW_TIMESTAMP;
// Copy the information to any additional log files
for (int i = 1; i < logFiles.Length; i++)
{
logFiles[i].BufferCallback = logFiles[0].BufferCallback;
logFiles[i].EventCallback = logFiles[0].EventCallback;
logFiles[i].LogFileMode = logFiles[0].LogFileMode;
handles[i] = handles[0];
}
sessionStartTime100ns = long.MaxValue;
sessionEndTime100ns = long.MinValue;
eventsLost = 0;
// Open all the traces
for (int i = 0; i < handles.Length; i++)
{
handles[i] = TraceEventNativeMethods.OpenTrace(ref logFiles[i]);
if (handles[i] == TraceEventNativeMethods.INVALID_HANDLE_VALUE)
{
Marshal.ThrowExceptionForHR(TraceEventNativeMethods.GetHRForLastWin32Error());
}
// Start time is minimum of all start times
if (logFiles[i].LogfileHeader.StartTime < sessionStartTime100ns)
{
sessionStartTime100ns = logFiles[i].LogfileHeader.StartTime;
}
// End time is maximum of all start times
if (logFiles[i].LogfileHeader.EndTime > sessionEndTime100ns)
{
sessionEndTime100ns = logFiles[i].LogfileHeader.EndTime;
}
// TODO do we even need log pointer size anymore?
// We take the max pointer size.
if ((int)logFiles[i].LogfileHeader.PointerSize > pointerSize)
{
pointerSize = (int)logFiles[i].LogfileHeader.PointerSize;
}
eventsLost += (int)logFiles[i].LogfileHeader.EventsLost;
}
// Real time providers don't set this to something useful
if (sessionStartTime100ns == 0)
{
sessionStartTime100ns = now;
}
if (sessionEndTime100ns == 0)
{
sessionEndTime100ns = long.MaxValue;
}
if (pointerSize == 0) // Real time does not set this (grrr).
{
pointerSize = sizeof(IntPtr);
Debug.Assert((logFiles[0].LogFileMode & TraceEventNativeMethods.EVENT_TRACE_REAL_TIME_MODE) != 0);
}
Debug.Assert(pointerSize == 4 || pointerSize == 8);
cpuSpeedMHz = (int)logFiles[0].LogfileHeader.CpuSpeedInMHz;
numberOfProcessors = (int)logFiles[0].LogfileHeader.NumberOfProcessors;
_QPCFreq = logFiles[0].LogfileHeader.PerfFreq;
if (_QPCFreq == 0) // Real time does not set this all the time
{
_QPCFreq = Stopwatch.Frequency;
Debug.Assert((logFiles[0].LogFileMode & TraceEventNativeMethods.EVENT_TRACE_REAL_TIME_MODE) != 0);
}
Debug.Assert(_QPCFreq != 0);
int ver = (int)logFiles[0].LogfileHeader.Version;
osVersion = new Version((byte)ver, (byte)(ver >> 8));
// Logic for looking up process names
processNameForID = new Dictionary <int, string>();
Kernel.ProcessStartGroup += delegate(ProcessTraceData data)
{
// Get just the file name without the extension. Can't use the 'Path' class because
// it tests to make certain it does not have illegal chars etc. Since KernelImageFileName
// is not a true user mode path, we can get failures.
string path = data.KernelImageFileName;
int startIdx = path.LastIndexOf('\\');
if (0 <= startIdx)
{
startIdx++;
}
else
{
startIdx = 0;
}
int endIdx = path.LastIndexOf('.');
if (endIdx <= startIdx)
{
endIdx = path.Length;
}
processNameForID[data.ProcessID] = path.Substring(startIdx, endIdx - startIdx);
};
}
