diff --git a/logging/Log.cs b/logging/Log.cs index 3ecf422..012eb7f 100644 --- a/logging/Log.cs +++ b/logging/Log.cs @@ -453,14 +453,14 @@ static public class log static public void exception( Exception ex, string msg, string cat = "", SourceLoc? loc = null, [CallerFilePath] string dbgPath = "", [CallerLineNumber] int dbgLine = -1, [CallerMemberName] string dbgMethod = "", [CallerArgumentExpression( "msg" )] string dbgExp = "" ) { - logBase( $"*******************************************************************************", + logBase( $"*******************************************************************************", LogType.Raw, dbgPath, dbgLine, dbgMethod, cat, dbgExp, loc ); logBase( $"{dbgMethod}: {msg} | Caught At:", LogType.Error, dbgPath, dbgLine, dbgMethod, cat, dbgExp, loc ); - logBase( $"{dbgPath}({dbgLine}): {dbgMethod}: ---------------", + logBase( $"{dbgPath}({dbgLine}): {dbgMethod}: ---------------", LogType.Raw, dbgPath, dbgLine, dbgMethod, cat, dbgExp, loc ); LogStackTrace( ex ); } - + [StackTraceHidden] @@ -1020,4 +1020,4 @@ static public class log private static ArrayList s_delegates = new ArrayList(); -} \ No newline at end of file +} diff --git a/logging/Tracing.cs b/logging/Tracing.cs index a7c70f3..1c77dac 100644 --- a/logging/Tracing.cs +++ b/logging/Tracing.cs @@ -10,292 +10,666 @@ using System.Diagnostics; using System.IO; using System.Threading; using System.Threading.Tasks; +using Microsoft.Diagnostics.NETCore.Client; +using System.Collections.Generic; +using System.Linq; +using System.Runtime.InteropServices; +using System.Diagnostics.Tracing; namespace Tracing { - /// - /// This is an example of using the Real-Time (non-file) based support of TraceLog to get stack traces for events. - /// - internal class TraceLogMonitor - { - /// - /// Where all the output goes. - /// - private static TextWriter Out = TextWriter.Null; + /// + /// A configurable, real-time EventPipe trace monitor for cross-platform use. + /// This class uses a fluent builder pattern to attach to a .NET process, + /// configure EventPipe providers, and process events in real-time. + /// + public class EventPipeTraceMonitor : IDisposable + { + private readonly int _pid; + private int _durationSec = 10; + private ClrTraceEventParser.Keywords _clrKeywords = ClrTraceEventParser.Keywords.None; + private bool _monitorCpu = false; + private readonly List _customProviders = new(); - public static void Run() - { - var monitoringTimeSec = 10; - - log.info("******************** RealTimeTraceLog DEMO ********************"); - log.info("This program Shows how to use the real-time support in TraceLog"); - log.info("We do this by showing how to monitor exceptions in real time "); - - log.info("This code depends on a Feature of Windows 8.1 (combined user and kernel sessions)"); - log.info("It will work on Win7 machines, however win7 can have only one kernel session"); - log.info("so it will disrupt any use of the kernel session on that OS. "); - - log.info("Note that this support is currently experimental and subject to change"); - - log.info("Monitoring .NET Module load and Exception events (with stacks)."); - log.info("Run some managed code (ideally that has exceptions) while the monitor is running."); +private Action _userCallback; + private EventPipeSession _session; + private TraceEventSource _traceLogSource; /// CHANGED + private Task _processingTask; - if (Environment.OSVersion.Version.Major * 10 + Environment.OSVersion.Version.Minor < 62) - { - log.info("This demo will preempt any use of the kernel provider. "); - } + private Timer _timer; - TraceEventSession session = null; + public EventPipeTraceMonitor( int processId ) + { + _pid = processId; + } - // Set up Ctrl-C to stop both user mode and kernel mode sessions - Console.CancelKeyPress += (object sender, ConsoleCancelEventArgs cancelArgs) => - { - if (session != null) - { - session.Dispose(); - } + // #################################################################### + // Builder Configuration Methods + // #################################################################### - cancelArgs.Cancel = true; - }; + public EventPipeTraceMonitor WithDuration( int seconds ) + { + _durationSec = seconds; + return this; + } - /* - // Cause an exception to be thrown a few seconds in (so we have something interesting to look at) - var exceptionGeneationTask = Task.Factory.StartNew(delegate - { - Thread.Sleep(3000); - ThrowException(); - }); - */ + /// + /// Adds a custom EventPipeProvider. + /// + public EventPipeTraceMonitor AddProvider( EventPipeProvider provider ) + { + _customProviders.Add( provider ); + return this; + } - Timer timer = null; + // #################################################################### + // Event Selection Methods + // #################################################################### - // Create the new session to receive the events. - // Because we are on Win 8 this single session can handle both kernel and non-kernel providers. - using (session = new TraceEventSession("TraceLogSession", TraceEventSessionOptions.Attach)) - { - // Enable the events we care about for the kernel - // For this instant the session will buffer any incoming events. - // Enabling kernel events must be done before anything else. - // Note that on Win7 it will turn on the one and only NT Kernel Session, and thus interrupt any kernel session in progress. - // On WIn8 you get a new session (like you would expect). - // - // Note that if you turn on the KernelTraceEventParser.Keywords.Profile, you can also get stacks for CPU sampling - // (every millisecond). (You can use the traceLogSource.Kernel.PerfInfoSample callback). - log.info("Enabling Image load, Process and Thread events. These are needed to look up native method names."); + public EventPipeTraceMonitor MonitorExceptions() + { + // EventPipe requires JIT/Loader/Stack keywords to resolve symbols + _clrKeywords |= ClrTraceEventParser.Keywords.Exception | + ClrTraceEventParser.Keywords.Stack | + ClrTraceEventParser.Keywords.Jit | + ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | + ClrTraceEventParser.Keywords.Loader; + return this; + } - try - { - session.EnableKernelProvider( - // KernelTraceEventParser.Keywords.Profile | // If you want CPU sampling events - // KernelTraceEventParser.Keywords.ContextSwitch | // If you want context switch events - // KernelTraceEventParser.Keywords.Thread | // If you want context switch events you also need thread start events. - KernelTraceEventParser.Keywords.ImageLoad | - KernelTraceEventParser.Keywords.Process, /****** The second parameter indicates which kernel events should have stacks *****/ - // KernelTraceEventParser.Keywords.ImageLoad | // If you want Stacks image load (load library) events - // KernelTraceEventParser.Keywords.Profile | // If you want Stacks for CPU sampling events - // KernelTraceEventParser.Keywords.ContextSwitch | // If you want Stacks for context switch events - KernelTraceEventParser.Keywords.None - ); - } - catch( Exception ex ) - { - log.error( $"{ex}" ); - } + public EventPipeTraceMonitor MonitorModuleLoads() + { + _clrKeywords |= ClrTraceEventParser.Keywords.Loader | + ClrTraceEventParser.Keywords.Stack | + ClrTraceEventParser.Keywords.Jit | + ClrTraceEventParser.Keywords.Threading | + ClrTraceEventParser.Keywords.PerfTrack | + ClrTraceEventParser.Keywords.JittedMethodILToNativeMap; + return this; + } + public EventPipeTraceMonitor MonitorCpuSamples() + { + _monitorCpu = true; + return this; + } - log.info("Enabling CLR Exception and Load events (and stack for those events)"); - try - { - // We are monitoring exception events (with stacks) and module load events (with stacks) - session.EnableProvider( - ClrTraceEventParser.ProviderGuid, - TraceEventLevel.Informational, - (ulong)(ClrTraceEventParser.Keywords.Jit | // Turning on JIT events is necessary to resolve JIT compiled code - ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | // This is needed if you want line number information in the stacks - ClrTraceEventParser.Keywords.Loader | // You must include loader events as well to resolve JIT compiled code. - ClrTraceEventParser.Keywords.Exception | // We want to see the exception events. - ClrTraceEventParser.Keywords.Stack)); // And stacks on all CLR events where it makes sense. + // #################################################################### + // Core Execution Methods + // #################################################################### - } - catch( Exception ex ) - { - log.error( $"{ex}" ); - } - - log.info("Enabling CLR Events to 'catch up' on JIT compiled code in running processes."); - try - { - // The CLR events turned on above will let you resolve JIT compiled code as long as the JIT compilation - // happens AFTER the session has started. To handle the case for JIT compiled code that was already - // compiled we need to tell the CLR to dump 'Rundown' events for all existing JIT compiled code. We - // do that here. - session.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Informational, - (ulong)(ClrTraceEventParser.Keywords.Jit | // We need JIT events to be rundown to resolve method names - ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | // This is needed if you want line number information in the stacks - ClrTraceEventParser.Keywords.Loader | // As well as the module load events. - ClrTraceEventParser.Keywords.StartEnumeration)); // This indicates to do the rundown now (at enable time) - - } - catch( Exception ex ) - { - log.error( $"{ex}" ); - } - - - // Because we care about symbols in native code or NGEN images, we need a SymbolReader to decode them. - - // There is a lot of messages associated with looking up symbols, but we don't want to clutter up - // The output by default, so we save it to an internal buffer you can ToString in debug code. - // A real app should make this available somehow to the user, because sooner or later you DO need it. - TextWriter SymbolLookupMessages = new StringWriter(); - // TextWriter SymbolLookupMessages = Out; // If you want the symbol debug spew to go to the output, use this. - - // By default a symbol Reader uses whatever is in the _NT_SYMBOL_PATH variable. However you can override - // if you wish by passing it to the SymbolReader constructor. Since we want this to work even if you - // have not set an _NT_SYMBOL_PATH, so we add the Microsoft default symbol server path to be sure/ - - log.info( $"Loading symbols from {SymbolPath.MicrosoftSymbolServerPath}" ); - var symbolPath = new SymbolPath(SymbolPath.SymbolPathFromEnvironment).Add(SymbolPath.MicrosoftSymbolServerPath); - - - SymbolReader symbolReader = new SymbolReader(SymbolLookupMessages, symbolPath.ToString()); - - // By default the symbol reader will NOT read PDBs from 'unsafe' locations (like next to the EXE) - // because hackers might make malicious PDBs. If you wish ignore this threat, you can override this - // check to always return 'true' for checking that a PDB is 'safe'. - symbolReader.SecurityCheck = (path => true); - - log.info("Open a real time TraceLog session (which understands how to decode stacks)."); - - try - { - using (TraceLogEventSource traceLogSource = TraceLog.CreateFromTraceEventSession(session)) - { - // We use this action in the particular callbacks below. Basically we pass in a symbol reader so we can decode the stack. - // Often the symbol reader is a global variable instead. - Action PrintEvent = ((TraceEvent data) => Print(data, symbolReader)); - - // We will print Exceptions and ModuleLoad events. (with stacks). - traceLogSource.Clr.ExceptionStart += PrintEvent; - traceLogSource.Clr.LoaderModuleLoad += PrintEvent; - // traceLogSource.Clr.All += PrintEvent; - - // If you want to see stacks for various other kernel events, uncomment these (you also need to turn on the events above) - traceLogSource.Kernel.PerfInfoSample += ((SampledProfileTraceData data) => Print(data, symbolReader)); - // traceLogSource.Kernel.ImageLoad += ((ImageLoadTraceData data) => Print(data, symbolReader)); - - // process events until Ctrl-C is pressed or timeout expires - log.info($"Waiting {monitoringTimeSec} sec for Events. Run managed code to see data. "); - log.info("Keep in mind there is a several second buffering delay"); - - // Set up a timer to stop processing after monitoringTimeSec - timer = new Timer(delegate (object state) - { - log.info($"Stopped Monitoring after {monitoringTimeSec} sec"); - if (session != null) - { - session.Dispose(); - } - - session = null; - }, null, monitoringTimeSec * 1000, Timeout.Infinite); - - traceLogSource.Process(); - } - } - catch( Exception ex ) - { - log.error( $"{ex}" ); - } + public void Start( Action onEventCallback ) + { + _userCallback = onEventCallback; + var providers = new List( _customProviders ); - } - log.info("Finished"); - if (timer != null) - { - timer.Dispose(); // Turn off the timer. - } - } - /// - /// Print data. Note that this method is called FROM DIFFERNET THREADS which means you need to properly - /// lock any read-write data you access. It turns out log.info is already thread safe so - /// there is nothing I have to do in this case. - /// - private static void Print(TraceEvent data, SymbolReader symbolReader) - { - // There are a lot of data collection start on entry that I don't want to see (but often they are quite handy - if (data.Opcode == TraceEventOpcode.DataCollectionStart) - { - return; - } - // V3.5 runtimes don't log the stack and in fact don't event log the exception name (it shows up as an empty string) - // Just ignore these as they are not that interesting. - if (data is ExceptionTraceData && ((ExceptionTraceData)data).ExceptionType.Length == 0) - { - return; - } - if (!data.ProcessName.Contains("Samples")) - { - return; - } + if( _clrKeywords != ClrTraceEventParser.Keywords.None ) + { + // Add the main CLR provider + providers.Add( new EventPipeProvider( + "Microsoft-Windows-DotNETRuntime", + EventLevel.Informational, + (long)_clrKeywords ) ); + } - log.info($"EVENT: {data}"); - var callStack = data.CallStack(); - if (callStack != null) - { - // Because symbol lookup is complex, error prone, and expensive TraceLog requires you to be explicit. - // Here we look up names in this call stack using the symbol reader. - ResolveNativeCode(callStack, symbolReader); - log.info($"CALLSTACK: {callStack.ToString()}" ); - } - } + if( _monitorCpu ) + { + // Add the CPU sampler provider + providers.Add( new EventPipeProvider( + "Microsoft-DotNETCore-SampleProfiler", + EventLevel.Informational ) ); + } - /// - /// Because it is expensive and often unnecessary, lookup of native symbols needs to be explicitly requested. - /// Here we do this for every frame in the stack. Note that this is not needed for JIT compiled managed code. - /// - private static void ResolveNativeCode(TraceCallStack callStack, SymbolReader symbolReader) - { - while (callStack != null) - { - var codeAddress = callStack.CodeAddress; - if (codeAddress.Method == null) - { - var moduleFile = codeAddress.ModuleFile; - if (moduleFile == null) - { - Trace.WriteLine(string.Format("Could not find module for Address 0x{0:x}", codeAddress.Address)); - } - else - { - codeAddress.CodeAddresses.LookupSymbolsForModule(symbolReader, moduleFile); - } - } - callStack = callStack.Caller; - } - } - // Force it not to be inlined so we see the stack. - [System.Runtime.CompilerServices.MethodImpl(System.Runtime.CompilerServices.MethodImplOptions.NoInlining)] - private static void ThrowException() - { - ThrowException1(); - } - // Force it not to be inlined so we see the stack. - [System.Runtime.CompilerServices.MethodImpl(System.Runtime.CompilerServices.MethodImplOptions.NoInlining)] - private static void ThrowException1() - { - log.info("Causing an exception to happen so a CLR Exception Start event will be generated."); - try - { - throw new Exception("This is a test exception thrown to generate a CLR event"); - } - catch (Exception) { } - } - } + + + + if( !providers.Any() ) + { + log.warn( "No trace providers configured. Monitor will not start." ); + return; + } + + try + { + var client = new DiagnosticsClient( _pid ); + log.info( $"Starting EventPipe session on PID {_pid} for {_durationSec}s..." ); + + // Start the session. requestRundown=true is critical + // to get symbols for code JIT-compiled before the session started. + _session = client.StartEventPipeSession( providers, requestRundown: true ); + + // Set up the timer to stop the session + _timer = new Timer( delegate + { + log.info( $"Monitoring duration ({_durationSec} sec) elapsed." ); + Stop(); + }, null, _durationSec * 1000, Timeout.Infinite ); + + // Create the TraceLogSource from the session's event stream + _traceLogSource = new EventPipeEventSource( _session.EventStream ); + // KEEP TraceLog.CreateFromTraceEventSession( _session ); + + // Register callbacks based on requested keywords + if( ( _clrKeywords & ClrTraceEventParser.Keywords.Exception ) != 0 ) + _traceLogSource.Clr.ExceptionStart += OnEvent; + if( ( _clrKeywords & ClrTraceEventParser.Keywords.Loader ) != 0 ) + { + _traceLogSource.Clr.LoaderModuleLoad += OnEvent; + _traceLogSource.Clr.All += OnAllEvents; + + } + //if( _monitorCpu ) + // _traceLogSource.CpuSpeedMHz += OnEvent; + + // Start processing the stream on a background thread. + // .Process() is a blocking call that runs until the stream ends. + _processingTask = Task.Run( () => + { + try + {/* _traceLogSource.Pro;*/ } + catch( Exception ex ) { log.error( $"Trace processing error: {ex.Message}" ); } + log.info( "Event processing finished." ); + } ); + } + catch( Exception ex ) + { + log.error( $"Failed to start EventPipe session: {ex.Message}" ); + } + + + + + } + + private void OnAllEvents( TraceEvent evt ) + { + log.info( $"EVENT: [PID:{evt.ProcessID}] -- {evt.EventName}" ); + } + + public void Stop() + { + if( _session != null ) + { + log.info( "Stopping session..." ); + _timer?.Dispose(); + _timer = null; + + // Stopping the session will end the stream, + // which causes traceLogSource.Process() to return. + _session.Stop(); + _session.Dispose(); + _session = null; + + _traceLogSource?.Dispose(); + _traceLogSource = null; + + // Wait for the processing task to complete + _processingTask?.Wait( 2000 ); + _processingTask = null; + } + } + + public void Dispose() + { + Stop(); + } + + /// + /// Internal event handler. + /// + private void OnEvent( TraceEvent data ) + { + // --- Pre-filtering --- + if( data.Opcode == TraceEventOpcode.DataCollectionStart ) + return; + if( data is ExceptionTraceData exd && exd.ExceptionType.Length == 0 ) + return; + + // --- Pass to user --- + _userCallback( data ); + } + } + + /// + /// A configurable, real-time ETW trace monitor. (Windows-Only) + /// This class uses a fluent builder pattern to configure and run a real-time + /// TraceEventSession, processing events through a user-provided callback. + /// + public class RealTimeTraceMonitor : IDisposable + { + private TraceEventSession _session; + private int _durationSec = 10; + private string _processFilter = null; + private KernelTraceEventParser.Keywords _kernelKeywords = KernelTraceEventParser.Keywords.ImageLoad | KernelTraceEventParser.Keywords.Process; + private ClrTraceEventParser.Keywords _clrKeywords = ClrTraceEventParser.Keywords.None; + private KernelTraceEventParser.Keywords _kernelStackKeywords = KernelTraceEventParser.Keywords.None; + private bool _enableRundown = false; + private bool _resolveNativeSymbols = false; + private readonly List> _eventRegistrars = new(); + private Action _userCallback; + private SymbolReader _symbolReader; + private readonly object _symbolReaderLock = new(); + private TextWriter _symbolLog = new StringWriter(); + private Timer _timer; + + // #################################################################### + // Builder Configuration Methods + // #################################################################### + + /// + /// Sets the monitoring duration in seconds. + /// + public RealTimeTraceMonitor WithDuration( int seconds ) + { + _durationSec = seconds; + return this; + } + + /// + /// Filters events to only include those from a process whose name contains this string. + /// + public RealTimeTraceMonitor FilterByProcess( string processName ) + { + _processFilter = processName; + return this; + } + + /// + /// Provides a TextWriter for detailed symbol lookup messages. + /// + public RealTimeTraceMonitor WithSymbolLog( TextWriter logWriter ) + { + _symbolLog = logWriter; + return this; + } + + // #################################################################### + // Event Selection Methods + // #################################################################### + + /// + /// Enables monitoring for CLR Exceptions (ExceptionStart). + /// Automatically enables JIT, Loader, and Stack keywords required for symbol resolution. + /// + public RealTimeTraceMonitor MonitorExceptions() + { + _clrKeywords |= ClrTraceEventParser.Keywords.Exception | + ClrTraceEventParser.Keywords.Stack | + ClrTraceEventParser.Keywords.Jit | + ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | + ClrTraceEventParser.Keywords.Loader; + _enableRundown = true; + _resolveNativeSymbols = true; // Native symbol resolution is often needed for full exception stacks + _eventRegistrars.Add( source => source.Clr.ExceptionStart += OnEvent ); + return this; + } + + /// + /// Enables monitoring for CLR Module Loads (LoaderModuleLoad). + /// Automatically enables JIT, Loader, and Stack keywords. + /// + public RealTimeTraceMonitor MonitorModuleLoads() + { + _clrKeywords |= ClrTraceEventParser.Keywords.Loader | + ClrTraceEventParser.Keywords.Stack | + ClrTraceEventParser.Keywords.Jit | + ClrTraceEventParser.Keywords.JittedMethodILToNativeMap; + _enableRundown = true; + _eventRegistrars.Add( source => source.Clr.LoaderModuleLoad += OnEvent ); + return this; + } + + /// + /// Enables monitoring for CPU Samples (PerfInfoSample). + /// + public RealTimeTraceMonitor MonitorCpuSamples() + { + _kernelKeywords |= KernelTraceEventParser.Keywords.Profile; + _kernelStackKeywords |= KernelTraceEventParser.Keywords.Profile; + _resolveNativeSymbols = true; // CPU samples require native symbol resolution + _eventRegistrars.Add( source => source.Kernel.PerfInfoSample += OnEvent ); + return this; + } + + /// + /// Enables monitoring for arbitrary Kernel events. + /// + /// Kernel keywords to enable. + /// Keywords to collect stacks for. + public RealTimeTraceMonitor MonitorKernelEvents( KernelTraceEventParser.Keywords events, KernelTraceEventParser.Keywords stackEvents = KernelTraceEventParser.Keywords.None ) + { + _kernelKeywords |= events; + _kernelStackKeywords |= stackEvents; + if( stackEvents != KernelTraceEventParser.Keywords.None ) + { + _resolveNativeSymbols = true; + } + return this; + } + + /// + /// Enables monitoring for arbitrary CLR events. + /// Note: For complex events, prefer the specific Monitor* methods. + /// + /// CLR keywords to enable. + public RealTimeTraceMonitor MonitorClrEvents( ClrTraceEventParser.Keywords events ) + { + _clrKeywords |= events; + if( ( events & ClrTraceEventParser.Keywords.Stack ) != 0 ) + { + _clrKeywords |= ClrTraceEventParser.Keywords.Jit | + ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | + ClrTraceEventParser.Keywords.Loader; + _enableRundown = true; + _resolveNativeSymbols = true; + } + return this; + } + + // #################################################################### + // Core Execution Methods + // #################################################################### + + /// + /// Starts the monitoring session and blocks until the duration expires or Ctrl+C is pressed. + /// + /// The callback to execute for each filtered event. + public void Start( Action onEventCallback ) + { + if( !OperatingSystem.IsWindows() ) + { + log.error( $"{nameof( RealTimeTraceMonitor )} is only supported on Windows (ETW)." ); + return; + } + + _userCallback = onEventCallback; + log.info( $"Starting {nameof( RealTimeTraceMonitor )} for {_durationSec} seconds." ); + + if( TraceEventSession.GetActiveSessionNames().Contains( "TraceLogMonitorSession" ) ) + { + log.warn( "Session 'TraceLogMonitorSession' is already active. Attaching." ); + } + + try + { + using( _session = new TraceEventSession( "TraceLogMonitorSession", TraceEventSessionOptions.Attach ) ) + { + // Set up Ctrl-C to stop the session + Console.CancelKeyPress += ( object sender, ConsoleCancelEventArgs cancelArgs ) => + { + cancelArgs.Cancel = true; + Stop(); + }; + + SetupProviders(); + SetupSymbolReader(); + + using( var traceLogSource = TraceLog.CreateFromTraceEventSession( _session ) ) + { + // Register all requested event callbacks + foreach( var registrar in _eventRegistrars ) + { + registrar( traceLogSource ); + } + + // Set up a timer to stop processing after the duration + _timer = new Timer( delegate ( object state ) + { + log.info( $"Monitoring duration ({_durationSec} sec) elapsed." ); + Stop(); + }, null, _durationSec * 1000, Timeout.Infinite ); + + log.info( "Processing events..." ); + traceLogSource.Process(); + log.info( "Event processing finished." ); + } + } + } + catch( Exception ex ) + { + log.error( $"Failed to start trace session: {ex.Message}" ); + log.error( "This often requires Admin privileges." ); + } + finally + { + _session = null; + } + } + + /// + /// Stops the monitoring session. + /// + public void Stop() + { + if( _session != null ) + { + log.info( "Stopping session..." ); + _session.Dispose(); + _session = null; + } + if( _timer != null ) + { + _timer.Dispose(); + _timer = null; + } + } + + public void Dispose() + { + Stop(); + } + + // #################################################################### + // Private Helper Methods + // #################################################################### + + private void SetupProviders() + { + log.info( $"Enabling Kernel Providers with keywords: {_kernelKeywords}" ); + try + { + _session.EnableKernelProvider( _kernelKeywords, _kernelStackKeywords ); + } + catch( Exception ex ) + { + log.error( $"Failed to enable Kernel provider: {ex}" ); + } + + if( _clrKeywords != ClrTraceEventParser.Keywords.None ) + { + log.info( $"Enabling CLR Provider with keywords: {_clrKeywords}" ); + try + { + _session.EnableProvider( + ClrTraceEventParser.ProviderGuid, + TraceEventLevel.Informational, + (ulong)_clrKeywords ); + } + catch( Exception ex ) + { + log.error( $"Failed to enable CLR provider: {ex}" ); + } + } + + if( _enableRundown ) + { + // Remove keywords not relevant for rundown + var rundownKeywords = ( _clrKeywords & ~( ClrTraceEventParser.Keywords.Exception | ClrTraceEventParser.Keywords.Stack ) ); + rundownKeywords |= ClrTraceEventParser.Keywords.StartEnumeration; + + log.info( $"Enabling CLR Rundown Provider with keywords: {rundownKeywords}" ); + try + { + _session.EnableProvider( + ClrRundownTraceEventParser.ProviderGuid, + TraceEventLevel.Informational, + (ulong)rundownKeywords ); + } + catch( Exception ex ) + { + log.error( $"Failed to enable CLR Rundown provider: {ex}" ); + } + } + } + + private void SetupSymbolReader() + { + if( _resolveNativeSymbols ) + { + log.info( "Setting up SymbolReader for native symbol resolution." ); + var symbolPath = new SymbolPath( SymbolPath.SymbolPathFromEnvironment ).Add( SymbolPath.MicrosoftSymbolServerPath ); + _symbolReader = new SymbolReader( _symbolLog, symbolPath.ToString() ); + // Allow reading PDBs from "unsafe" locations (next to EXE) + _symbolReader.SecurityCheck = ( path => true ); + } + } + + /// + /// Primary event handler. + /// This method is called from multiple threads and must be thread-safe. + /// + private void OnEvent( TraceEvent data ) + { + // --- Pre-filtering --- + if( data.Opcode == TraceEventOpcode.DataCollectionStart ) + return; + if( data is ExceptionTraceData exd && exd.ExceptionType.Length == 0 ) + return; + + // --- Process filter --- + if( _processFilter != null && !data.ProcessName.Contains( _processFilter, StringComparison.OrdinalIgnoreCase ) ) + { + return; + } + + // --- Symbol Resolution --- + var callStack = data.CallStack(); + if( callStack != null && _resolveNativeSymbols ) + { + ResolveNativeStack( callStack ); + } + + // --- Pass to user --- + _userCallback( data ); + } + + /// + /// Resolves native symbols for a given call stack. + /// This method locks the SymbolReader, as it is not thread-safe. + /// + private void ResolveNativeStack( TraceCallStack callStack ) + { + if( _symbolReader == null ) + return; + + lock( _symbolReaderLock ) + { + while( callStack != null ) + { + var codeAddress = callStack.CodeAddress; + if( codeAddress.Method == null ) + { + var moduleFile = codeAddress.ModuleFile; + if( moduleFile != null ) + { + codeAddress.CodeAddresses.LookupSymbolsForModule( _symbolReader, moduleFile ); + } + } + callStack = callStack.Caller; + } + } + } + } + + /// + /// Example implementation of the RealTimeTraceMonitor utility. + /// + internal class TraceLogMonitor + { + public static void Run() + { + log.info( "******************** RealTimeTraceLog DEMO ********************" ); + + // Define a thread-safe callback to process events + Action printCallback = ( TraceEvent data ) => + { + // log.info is assumed to be thread-safe + // Note: EventPipe data does not have ProcessName, as it's scoped to the process. + log.info( $"EVENT: [PID:{data.ProcessID}] -- {data.EventName}" ); + + var stack = data.CallStack(); + if( stack != null ) + { + log.info( $"CALLSTACK: {stack}" ); + } + }; + + // Run an exception generator in the background + Task.Factory.StartNew( delegate + { + Thread.Sleep( 3000 ); + ThrowException(); + } ); + + try + { + if( OperatingSystem.IsWindows() ) + { + log.info( "Windows detected. Using ETW-based RealTimeTraceMonitor." ); + using( var monitor = new RealTimeTraceMonitor() ) + { + monitor.WithDuration( 10 ) + .MonitorExceptions() + .MonitorModuleLoads() + .Start( printCallback ); + } + } + else + { + log.info( "Non-Windows detected. Using EventPipe-based EventPipeTraceMonitor." ); + int currentPid = Process.GetCurrentProcess().Id; + using( var monitor = new EventPipeTraceMonitor( currentPid ) ) + { + monitor.WithDuration( 10 ) + .MonitorExceptions() + .MonitorModuleLoads() + //.MonitorCpuSamples() // Note: EventPipe CPU sampling is very noisy + .Start( printCallback ); + } + } + } + catch( Exception ex ) + { + log.error( $"Monitoring failed: {ex}" ); + } + + log.info( "Finished monitoring." ); + } + + // --- Exception generation helpers --- + + [System.Runtime.CompilerServices.MethodImpl( System.Runtime.CompilerServices.MethodImplOptions.NoInlining )] + private static void ThrowException() + { + ThrowException1(); + } + + [System.Runtime.CompilerServices.MethodImpl( System.Runtime.CompilerServices.MethodImplOptions.NoInlining )] + private static void ThrowException1() + { + log.info( "Causing an exception to happen so a CLR Exception Start event will be generated." ); + try + { + throw new Exception( "This is a test exception thrown to generate a CLR event" ); + } + catch( Exception ) { } + } + } } diff --git a/ser/XmlSer.cs b/ser/XmlSer.cs index b6a744e..310d0b4 100644 --- a/ser/XmlSer.cs +++ b/ser/XmlSer.cs @@ -280,6 +280,9 @@ public class TypeMetaCache var (isProxy, proxyDef) = FindProxy( type ); + //Dont need to sort since we just run through the attributes first, then the nodes + //members.Sort( ( a, b ) => ( a.IsPodAttribute.Int < b.IsPodAttribute.Int ) ? 1 : -1); + return new TypeInfo( type, members, @@ -310,10 +313,10 @@ public class TypeMetaCache - private void ProcessMember( MemberInfo mi, bool doMember, HashSet childrenOverridden, bool doImpls, bool isImm, List members ) + private void ProcessMember( MemberInfo mi, bool doMemberType, HashSet childrenOverridden, bool doImpls, bool isImm, List members ) { List children = new( childrenOverridden ); - var (hasDo, hasDont, hasImpl, propName) = GetMemberAttributes( mi, out var actualMiForAtts, children ); + var (hasDo, hasDont, hasImpl, propName, serTypess) = GetMemberAttributes( mi, out var actualMiForAtts, children ); if( hasDont ) return; @@ -326,11 +329,14 @@ public class TypeMetaCache if( mi.GetCustomAttribute( true ) != null ) return; - if( !(doMember | hasImpl | hasDo) ) + if( !( + hasDo | + doMemberType | + ( hasImpl & children.Any() ) + ) ) return; - var miType = ( mi is FieldInfo fi ) ? fi.FieldType : ( (PropertyInfo)mi ).PropertyType; // CHANGED (moved up) string name = mi.Name; @@ -350,8 +356,6 @@ public class TypeMetaCache var blankHashSet = new HashSet(); - - //Type realMemberType = miType; if( hasImpl && children.Any() ) { //List specialMembers = new(); @@ -445,7 +449,7 @@ public class TypeMetaCache } - private (bool hasDo, bool hasDont, bool hasImpl, string propName) GetMemberAttributes( MemberInfo mi, out MemberInfo actualMi, List children ) + private (bool hasDo, bool hasDont, bool hasImpl, string propName, ser.Types serTypess) GetMemberAttributes( MemberInfo mi, out MemberInfo actualMi, List children ) { actualMi = mi; string propName = ""; @@ -481,7 +485,9 @@ public class TypeMetaCache attDo, attDont, doImpls, - propName + propName, + + serTypes ); } @@ -680,7 +686,7 @@ public class XmlSer // : IFormatter XmlDocument doc = new XmlDocument(); try { doc.Load( reader ); } - catch( Exception ex ) { log.error( $"XML Load failed: {ex.Message}" ); return null; } + catch( Exception ex ) { log.exception( ex, $"XML Load failed: {ex.Message}" ); return null; } if( doc.DocumentElement == null ) return null; @@ -697,8 +703,13 @@ public class XmlSer // : IFormatter using var reader = XmlReader.Create( stream, new XmlReaderSettings { IgnoreWhitespace = true } ); XmlDocument doc = new XmlDocument(); try - { doc.Load( reader ); } - catch( Exception ex ) { log.error( $"XML Load failed: {ex.Message}" ); return; } + { + doc.Load( reader ); + } + catch( Exception ex ) + { + log.exception( ex, $"XML Load failed: {ex.Message}" ); return; + } if( doc.DocumentElement == null ) return; diff --git a/ser/XmlSer_Core.cs b/ser/XmlSer_Core.cs index 50a5835..2ec98c3 100644 --- a/ser/XmlSer_Core.cs +++ b/ser/XmlSer_Core.cs @@ -20,8 +20,8 @@ public partial class PrimitiveHandler : ser.ITypeHandler { var typeCode = Type.GetTypeCode( ti.Type ); var typeNotObject = Type.GetTypeCode( ti.Type ) != TypeCode.Object; - var isString = ti.Type == typeof( string ); - return typeNotObject | isString; + //var isString = ti.Type == typeof( string ); + return typeNotObject; } } @@ -148,7 +148,7 @@ public partial class ObjectHandler : ITypeHandler } catch( Exception ex ) { - log.error( $"Failed to create instance of {type.Name}: {ex.Message}" ); + log.exception( ex, $"Failed to create instance of {type.Name}: {ex.Message}" ); return (null, -1); } diff --git a/ser/XmlSer_Write.cs b/ser/XmlSer_Write.cs index 9cdb9ff..8f33925 100644 --- a/ser/XmlSer_Write.cs +++ b/ser/XmlSer_Write.cs @@ -150,31 +150,37 @@ public partial class ObjectHandler : ITypeHandler { foreach( var memberMeta in ti.Members ) { + if( !memberMeta.IsPodAttribute ) continue; + var value = memberMeta.GetValue( obj ); if( value != null ) { - // If POD-Attribute, write attribute - if( memberMeta.IsPodAttribute ) + try { - try - { - writer.WriteAttributeString( memberMeta.XmlName, value.ToString() ); - } - catch( Exception ex ) - { - log.error( $"Writing Att {memberMeta.XmlName} = [{value}]" ); - } + writer.WriteAttributeString( memberMeta.XmlName, value.ToString() ); } - else + catch( Exception ex ) { - try - { - xml.WriteNode( writer, value, memberMeta.XmlName, memberMeta.Type, false ); - } - catch( Exception ex ) - { - log.error( $"Writing Node {memberMeta.XmlName} = [{value}]" ); - } + log.exception( ex, $"Writing Att {memberMeta.XmlName} = [{value}]" ); + } + } + } + + + foreach( var memberMeta in ti.Members ) + { + if( memberMeta.IsPodAttribute ) continue; + + var value = memberMeta.GetValue( obj ); + if( value != null ) + { + try + { + xml.WriteNode( writer, value, memberMeta.XmlName, memberMeta.Type, false ); + } + catch( Exception ex ) + { + log.exception( ex, $"Writing Node {memberMeta.XmlName} = [{value}]" ); } } diff --git a/util/Pod.cs b/util/Pod.cs new file mode 100644 index 0000000..3032864 --- /dev/null +++ b/util/Pod.cs @@ -0,0 +1,13 @@ + + +using System; + +//namespace lib; + +public static class PodExt +{ + extension( Boolean b ) + { + public int Int => b?1:0; + } +};