Compare commits
3 Commits
| Author | SHA1 | Date | |
|---|---|---|---|
| d1f1694678 | |||
| cc52660989 | |||
| 20c3af53e4 |
72
AGENTS.md
72
AGENTS.md
@ -1,58 +1,69 @@
|
||||
|
||||
# SharpLib and general coding guidelines
|
||||
|
||||
## 0. PERFORMANCE. Title it 0. AXIOM: HIGH-PERFORMANCE / ZERO-ALLOCATION
|
||||
|
||||
* **Zero Allocation Default:** Assume all code runs in a 60hz+ game loop or high-throughput pipeline unless marked `[ColdPath]`.
|
||||
* **NO LINQ:** `using System.Linq;` is strictly forbidden in core logic. Use `for` loops, arrays, or `Span<T>`/`ReadOnlySpan<T>`.
|
||||
* **NO Hidden Closures:** Do not use lambdas or delegates that capture local variables. If a lambda is necessary, make it `static` and pass state explicitly.
|
||||
* **Struct Semantics:**
|
||||
* Pass readonly structs using `in` or `ref readonly`.
|
||||
* Do not pass `struct` to interfaces unless constrained by generics (`where T : struct`), to prevent boxing.
|
||||
* **String Allocation:** NO string interpolation (`$""`) on the hot path. Use static strings, `string.Create`, or format into pooled buffers.
|
||||
* **Async/Task Overhead:** Default to synchronous execution for immediate state changes. If async is mandatory on a hot path, use `ValueTask<T>`, never `Task<T>`.
|
||||
* **Collections:** No `List<T>.Add()` inside tight loops without pre-sizing the capacity. Prefer array pooling (`ArrayPool<T>.Shared`).
|
||||
|
||||
## 1. CORE PHILOSOPHY
|
||||
|
||||
* **Leaky Abstractions:** All abstractions are always leaky. Do not hide complexity. Expose failure modes, costs, and "why" parameters.
|
||||
* **Visual Cost:** "Expensive things must look expensive." No hidden RPCs. Use explicit Message structs and `Send` methods.
|
||||
* **Fast & Introspectable:** Code must be highly performant (hot-path aware) but deeply debuggable (`log`, `DebugOld`, `reason` strings).
|
||||
* **Leaky Abstractions:** All abstractions are always leaky. Do not hide complexity. Expose failure modes, costs, and "reason" parameters.
|
||||
* **Visual Cost:** "Expensive things must look expensive." No hidden RPCs. Use explicit Message structs and `Send` methods instead of Rpcs
|
||||
* **Fast & Introspectable:** Code must be highly performant (hot-path aware) but deeply debuggable (`log`, `DebugOld`, `reason` strings). These are there to make debugging
|
||||
from console or log file possible
|
||||
|
||||
## 2. NAMING & SEMANTICS
|
||||
|
||||
* **Leaf Libraries:** Core libs (`io`, `imm`, `net`, `log`) are 2-5 chars. **NEVER** use `using` for them. Always type the prefix (e.g., `imm.Process`).
|
||||
* **No Redundancy:**
|
||||
* **Leaf Libraries:** Core libs (`io`, `imm`, `net`, `log`) are 2-5 chars. **NEVER** include using {namespace}; for core libs or any short namespace
|
||||
* **No Redundancy:In Names**
|
||||
* **No "Get":** `Player()` not `GetPlayer()`.
|
||||
* **No Echo:** `Send(msg)` not `SendMsg(msg)`.
|
||||
* **No "I" Prefix:** Interfaces are `Renderer`, not `IRenderer`.
|
||||
* **Architecture:** Slow/Pausable Realtime. Entity Component System (Pub/Sub).
|
||||
|
||||
## 3. LOGGING (`log` static class)
|
||||
|
||||
* **Constraint:** **NO** `Console.WriteLine`, `Debug.WriteLine`, or `ILogger`.
|
||||
* **Mechanism:** The logging system is very fast. It only queues the log on the main thread. It collects the caller debug info, and uses the directory name of the file for a default category (this can be overridden)
|
||||
* **Functional Tracing:**
|
||||
* `var x = log.info( $"Got {log.var(Calc())} from the calculation" );` // This both logs the info and prints what happened
|
||||
* **Standard:** `log.info`, `log.debug`, `log.warn`, `log.error`.
|
||||
* **Finer grained:** `log.trace`, `log.high`
|
||||
* Use log.exception( ex, $"[what was trying to be done]" );
|
||||
* **Introspection:** `log.logProps(obj, "Header")` and `log.exception(ex, "Context")`.
|
||||
* put important info as far to the left as possible, even at the cost of poor wording
|
||||
* **Introspection:** `log.props(obj, "Header")` and `log.exception(ex, "Context")`.
|
||||
* **Information** put important info as far to the left as possible, even at the cost of poor wording
|
||||
|
||||
## 4. IMMUTABLE STATE (`io`, `imm`)
|
||||
|
||||
* **Rule:** Objects inheriting `Versioned<T>`, `Recorded<T>`, `Timed<T>` are **IMMUTABLE**.
|
||||
* **Change Pipeline:** MUST use `Process`.
|
||||
* **Change Pipeline:** MUST use `imm.Process`.
|
||||
* **Ref Helper (Preferred):** `imm.Process(ref _state, s => s with { X = 1 }, "Reason");`
|
||||
* **Instance:** `_state = _state.Process(s => s with { X = 1 }, "Reason");`
|
||||
* **The "Hole Punch":** Always propagate a `string reason` parameter in your methods to feed the `Process` log.
|
||||
* **History:** `obj.DebugOld` is for **DEBUG ONLY**. Do not base game logic on it.
|
||||
* **The "Hole Punch":** Always propagate a `string reason` parameter in your methods to feed the `imm.Process` log.
|
||||
* **History:** `obj.DebugOld` is for **DEBUG ONLY**. Do not base program logic on it.
|
||||
|
||||
## 5. Visual Cost
|
||||
|
||||
* Unless something is a function call, it should look like a function call. For example RPCs are bad, sending a message is good.
|
||||
* Network/IO/Expensive operations MUST NOT masquerade as local function calls. Require explicit structural allocation.
|
||||
* **No RPCs:** Do not make network calls look like functions.
|
||||
* **Pattern:** Construct Struct -> Send.
|
||||
* *Bad:* `proxy.Move(x,y)`
|
||||
* *Good:* `Net.Send(new MoveMsg(x,y))`
|
||||
|
||||
## FEW-SHOT EXAMPLES (Strictly Imitate)
|
||||
## 6. FEW-SHOT EXAMPLES (Strictly Imitate)
|
||||
|
||||
<csharp_examples>
|
||||
```csharp
|
||||
// 1. NAMING & LOGGING
|
||||
// ** NAMING & LOGGING
|
||||
// Explicit 'log' usage, no 'Get', no 'Console'
|
||||
public void Init()
|
||||
{
|
||||
log.startup( "log/current_project.log" );
|
||||
log.startup( "log/current_project.log", log.Endpoints.All );
|
||||
|
||||
var waitTime = 1.0f;
|
||||
|
||||
@ -60,19 +71,20 @@ ## FEW-SHOT EXAMPLES (Strictly Imitate)
|
||||
|
||||
try
|
||||
{
|
||||
obj.SomeOperation();
|
||||
obj?.SomeOperation();
|
||||
}
|
||||
catch( Exception ex )
|
||||
{
|
||||
log.exception( ex, $"" );
|
||||
//Logs the exception name, message, the reason, the stack
|
||||
log.exception( ex, $"SomeOperation failed" );
|
||||
}
|
||||
|
||||
// 2. IMMUTABLE PROCESS
|
||||
// ** IMMUTABLE PROCESS
|
||||
// Reason "Init" passed down. Ref pattern used.
|
||||
imm.Process(ref _state, s => s with { Ready = true }, "Init");
|
||||
}
|
||||
|
||||
// 3. LOGIC FLOW
|
||||
// ** LOGIC FLOW
|
||||
public void Update(float dt)
|
||||
{
|
||||
// 'Player()' not 'GetPlayer()'
|
||||
@ -85,9 +97,21 @@ ## FEW-SHOT EXAMPLES (Strictly Imitate)
|
||||
}
|
||||
}
|
||||
|
||||
// 5. INTROSPECTION API
|
||||
// "Punching a hole" with the reason parameter
|
||||
public void Equip(Item i, string reason = "Equip")
|
||||
|
||||
// ** "Punching a hole" with the reason parameter
|
||||
public void Equip(Item i, string reason /*No default so a reason will be passed in*/ )
|
||||
{
|
||||
imm.Process( ref inv, s => s.Add(i), reason);
|
||||
}
|
||||
|
||||
. . .
|
||||
|
||||
// Somewhere else in project
|
||||
public void PlayerSwappedWeapons( Player pl )
|
||||
{
|
||||
Equip( _item, $"Player {pl.Name} swapped weapons (PlayerSwappedWeapons)" );
|
||||
}
|
||||
|
||||
```
|
||||
|
||||
<csharp_examples>
|
||||
|
||||
516
archive/logging/GC.cs
Normal file
516
archive/logging/GC.cs
Normal file
@ -0,0 +1,516 @@
|
||||
using lib;
|
||||
using Microsoft.Diagnostics.NETCore.Client;
|
||||
using Microsoft.Diagnostics.Tracing;
|
||||
using Microsoft.Diagnostics.Tracing.Etlx;
|
||||
using Microsoft.Diagnostics.Tracing.EventPipe;
|
||||
using Microsoft.Diagnostics.Tracing.Parsers;
|
||||
using Microsoft.Diagnostics.Tracing.Parsers.Clr;
|
||||
using Microsoft.Diagnostics.Tracing.Parsers.Kernel;
|
||||
using Microsoft.Diagnostics.Tracing.Session;
|
||||
using System;
|
||||
using System.Collections.Concurrent;
|
||||
using System.Collections.Generic;
|
||||
using System.Collections.Immutable;
|
||||
using System.Diagnostics;
|
||||
using System.Diagnostics.Tracing;
|
||||
using System.IO;
|
||||
using System.Linq;
|
||||
using System.Runtime.InteropServices;
|
||||
using System.Runtime.Remoting;
|
||||
using System.Text;
|
||||
using System.Threading;
|
||||
using System.Threading.Tasks;
|
||||
using System.Xml;
|
||||
using TraceKeywords = Microsoft.Diagnostics.Tracing.Parsers.ClrTraceEventParser.Keywords;
|
||||
|
||||
|
||||
public static class LogGCExt
|
||||
{
|
||||
public static string MethodInfo( TraceEvent te, string prefix = "Method" )
|
||||
{
|
||||
return $"{te.PayloadStringByName( $"{prefix}Namespace" )}.{te.PayloadStringByName( $"{prefix}Name" )}{te.PayloadStringByName( $"{prefix}Signature" )}";
|
||||
}
|
||||
|
||||
public static string Get( this TraceEvent te, string name, string def = "" ) => te.PayloadStringByName( name ) ?? def;
|
||||
|
||||
public static T Get<T>( this TraceEvent te, string name, T def = default )
|
||||
{
|
||||
var index = te.PayloadIndex( name );
|
||||
|
||||
if( index <= 0 )
|
||||
return default;
|
||||
|
||||
var value = te.PayloadValue( index );
|
||||
|
||||
|
||||
if( value.GetType() != typeof( T ) )
|
||||
{
|
||||
log.warn( $"In {te.ID} Payload {name} is type {value.GetType().FriendlyName()} not {typeof( T ).FriendlyName()}" );
|
||||
return default;
|
||||
}
|
||||
|
||||
return (T)value;
|
||||
}
|
||||
|
||||
|
||||
}
|
||||
|
||||
|
||||
public class LogGC
|
||||
{
|
||||
static ImmutableHashSet<string> blacklist;
|
||||
static ImmutableHashSet<string> stacklist;
|
||||
|
||||
static LogGC()
|
||||
{
|
||||
blacklist = ImmutableHashSet.Create(
|
||||
"FAKE_TEST",
|
||||
"GC/BulkMovedObjectRanges",
|
||||
|
||||
/*
|
||||
"GC/BulkSurvivingObjectRanges",
|
||||
"GC/BulkRootStaticVar",
|
||||
"GC/BulkNode",
|
||||
"GC/BulkEdge",
|
||||
"GC/BulkRootEdge",
|
||||
"GC/FinalizeObject",
|
||||
"GC/SetGCHandle",
|
||||
"GC/DestoryGCHandle",
|
||||
"GC/MarkWithType",
|
||||
"GC/SuspendEEStart",
|
||||
"GC/SuspendEEStop",
|
||||
|
||||
"GC/RestartEEStart",
|
||||
"GC/RestartEEStop",
|
||||
|
||||
"GC/FinalizersStart",
|
||||
// "GC/FinalizersStop", //Keep this one since it has details
|
||||
|
||||
"GC/GenerationRange",
|
||||
"GC/FitBucketInfo",
|
||||
|
||||
"TieredCompilation/BackgroundJitStart",
|
||||
|
||||
"Type/BulkType",
|
||||
"TypeLoad/Start",
|
||||
|
||||
"Method/R2RGetEntryPointStart",
|
||||
"Method/MethodDetails",
|
||||
"Method/MemoryAllocatedForJitCode",
|
||||
"Method/JittingStarted",
|
||||
"Method/ILToNativeMap",
|
||||
|
||||
"ThreadPoolWorkerThread/Wait",
|
||||
|
||||
"ILStub/StubGenerated"
|
||||
*/
|
||||
"FAKE_END_IS_NOTHING"
|
||||
|
||||
);
|
||||
stacklist = ImmutableHashSet.Create( "{TEST_ITEM}" );
|
||||
|
||||
log.endpointForCat( "Method/MemoryAllocatedForJitCode", log.Endpoints.File );
|
||||
log.endpointForCat( "TypeLoad/Stop", log.Endpoints.File );
|
||||
log.endpointForCat( "GC/BulkRootStaticVar", log.Endpoints.File );
|
||||
log.endpointForCat( "GC/BulkNode", log.Endpoints.File );
|
||||
log.endpointForCat( "GC/BulkRootStaticVar", log.Endpoints.File );
|
||||
|
||||
}
|
||||
|
||||
static public void RegisterObjectId( object obj )
|
||||
{
|
||||
/*
|
||||
var gchWeak = GCHandle.Alloc( obj, GCHandleType.Weak );
|
||||
var gchNRML = GCHandle.Alloc( obj, GCHandleType.Normal );
|
||||
|
||||
var intPtrWeak = GCHandle.ToIntPtr( gchWeak );
|
||||
var intPtrNRML = GCHandle.ToIntPtr( gchNRML );
|
||||
|
||||
//var intPtr = Marshal.GetIUnknownForObject( obj );
|
||||
var intPtr = 0; //gchNRML.AddrOfPinnedObject();
|
||||
|
||||
//Marshal.GetTypedObjectForIUnknown()
|
||||
|
||||
// 0x00000003400111C0
|
||||
// 0000000000000000
|
||||
|
||||
log.info( $"Log ObjectIDs: 0x{intPtrNRML.ToString("X"):0000000000000000} 0x{intPtrWeak.ToString("X"):0000000000000000}" );
|
||||
//*/
|
||||
}
|
||||
|
||||
|
||||
public static Action<TraceEvent> LogCategoryFunc( string catIn )
|
||||
{
|
||||
return ( TraceEvent te ) =>
|
||||
{
|
||||
var cat = catIn;
|
||||
|
||||
if( blacklist.Contains( te.EventName ) )
|
||||
return;
|
||||
|
||||
{
|
||||
var methodBeingCompiledNamespace = te.Get( "MethodBeingCompiledNamespace" );
|
||||
if( ( methodBeingCompiledNamespace.StartsWith( "Microsoft" ) || methodBeingCompiledNamespace.StartsWith( "System" ) ) )
|
||||
return;
|
||||
}
|
||||
|
||||
{
|
||||
var methodNamespace = te.PayloadStringByName( "MethodNamespace" ) ?? "";
|
||||
if( ( methodNamespace.StartsWith( "Microsoft" ) || methodNamespace.StartsWith( "System" ) ) )
|
||||
return;
|
||||
}
|
||||
|
||||
{
|
||||
var ns = te.PayloadStringByName( "TypeName" ) ?? "";
|
||||
if( ( ns.StartsWith( "Microsoft" ) || ns.StartsWith( "System" ) ) )
|
||||
return;
|
||||
}
|
||||
|
||||
|
||||
|
||||
{
|
||||
var ns = te.PayloadStringByName( "TypeLoad/Stop" ) ?? "";
|
||||
if( ns.StartsWith( "Godot" ) )
|
||||
return;
|
||||
}
|
||||
|
||||
{
|
||||
var payloadIndex = te.PayloadIndex( "count" );
|
||||
|
||||
if( payloadIndex > 0 )
|
||||
{
|
||||
var count = (int)te.PayloadValue( payloadIndex );
|
||||
if( count > 16 )
|
||||
return;
|
||||
}
|
||||
}
|
||||
|
||||
//<Event EventName="Method/JittingStarted" MethodILSize="0x00000059" MethodNamespace="NilEvent" MethodName="DebugString" MethodSignature="instance class System.String ()" ClrInstanceID="0"/>
|
||||
//<Event EventName="Method/LoadVerbose" MethodStartAddress="0x00000003045736B8" MethodSize="0x000001BC" MethodToken="0x060001BB" MethodFlags="Jitted" MethodNamespace="NilEvent" MethodName="DebugString" MethodSignature="instance class System.String ()" ClrInstanceID="0" ReJITID="0x00000000" OptimizationTier="MinOptJitted"/>
|
||||
|
||||
//<Event EventName="Method/InliningFailed" MethodBeingCompiledNamespace="dynamicClass" MethodBeingCompiledName="InvokeStub_EventAttribute.set_Message" MethodBeingCompiledNameSignature="class System.Object (class System.Object,class System.Object,int*)" InlinerNamespace="dynamicClass" InlinerName="InvokeStub_EventAttribute.set_Message" InlinerNameSignature="class System.Object (class System.Object,class System.Object,int*)" InlineeNamespace="System.Diagnostics.Tracing.EventAttribute" InlineeName="set_Message" InlineeNameSignature="instance void (class System.String)" FailAlways="False" FailReason="uses NextCallReturnAddress intrinsic" ClrInstanceID="0"/>
|
||||
|
||||
if( !te.EventName.StartsWith( "EventID" ) )
|
||||
{
|
||||
var logDetails = "";
|
||||
// Custom event displays
|
||||
if( te.EventName == "Method/LoadVerbose" )
|
||||
{
|
||||
var optTier = te.Get( "OptimizationTier" );
|
||||
var methodNamespace = te.Get( "MethodNamespace" );
|
||||
|
||||
if( optTier == "MinOptJitted" )
|
||||
return;
|
||||
if( methodNamespace.StartsWith( "FastSerialization" ) )
|
||||
return;
|
||||
|
||||
log.info( $"{optTier} {LogGCExt.MethodInfo( te )}", cat: te.EventName );
|
||||
|
||||
return;
|
||||
//logDetails = "| Details: ";
|
||||
}
|
||||
else if( te.EventName.StartsWith( "Method/Inlining" ) )
|
||||
{
|
||||
var methodNamespace = te.Get( "MethodBeingCompiledNamespace" );
|
||||
|
||||
if( methodNamespace.StartsWith( "FastSerialization" ) )
|
||||
return;
|
||||
|
||||
log.info( $"Inlining {te.Get( "FailReason" )} {te.Get( "OptimizationTier" )} {LogGCExt.MethodInfo( te, "MethodBeingCompiled" )}", cat: te.EventName );
|
||||
|
||||
return;
|
||||
//logDetails = "| Details: ";
|
||||
}
|
||||
else if( te.EventName == "Type/BulkType" )
|
||||
{
|
||||
var val = te.ToString();
|
||||
|
||||
XmlDocument doc = new();
|
||||
|
||||
var stream = new MemoryStream();
|
||||
var writer = new StreamWriter( stream );
|
||||
writer.Write( val );
|
||||
writer.Flush();
|
||||
stream.Position = 0;
|
||||
|
||||
doc.Load( stream );
|
||||
|
||||
var root = doc.DocumentElement;
|
||||
|
||||
XmlNodeList children = root.ChildNodes;
|
||||
|
||||
foreach( var child in children )
|
||||
{
|
||||
var node = child as XmlElement;
|
||||
log.info( $"Child: {node.Name}" );
|
||||
}
|
||||
|
||||
return;
|
||||
}
|
||||
else if( te.EventName == "TypeLoad/Stop" )
|
||||
{
|
||||
/*
|
||||
var typeName = te.PayloadStringByName( "TypeName" );
|
||||
if( typeName.StartsWith( "Godot." ) )
|
||||
return;
|
||||
|
||||
log.info( $"{typeName} Level: {te.PayloadStringByName( "LoadLevel" )}", cat: te.EventName );
|
||||
//*/
|
||||
|
||||
return;
|
||||
|
||||
//logDetails = "| Details: ";
|
||||
}
|
||||
else if( te.EventName.StartsWith( "Method/R2RGetEntryPoint" ) )
|
||||
{
|
||||
log.info( $"{LogGCExt.MethodInfo( te )} Entry: {te.PayloadStringByName( "EntryPoint" )}", cat: te.EventName );
|
||||
return;
|
||||
//logDetails = "| Details: ";
|
||||
}
|
||||
else if( te.EventName.StartsWith( "Contention/LockCreated" ) )
|
||||
{
|
||||
// "Contention/Start" AssociatedObjectID
|
||||
// System.Runtime.InteropServices.GCHandle.FromIntPtr(
|
||||
|
||||
var lockId = te.Get<UInt64>( "LockID" );
|
||||
var objId = te.Get<UInt64>( "AssociatedObjectID" );
|
||||
|
||||
var testObj = Marshal.GetIUnknownForObject( objId );
|
||||
|
||||
var intPtrStr = te.PayloadStringByName( "AssociatedObjectID" ).Substring( 2 );
|
||||
|
||||
try
|
||||
{
|
||||
//var intPtr = Convert.ToUInt64( intPtrStr, 16 );
|
||||
|
||||
//var gch = System.Runtime.InteropServices.GCHandle.FromIntPtr( intPtr );
|
||||
var gch = new GCHandle();
|
||||
|
||||
|
||||
//*
|
||||
var allocated = gch.IsAllocated;
|
||||
var obj = gch.Target;
|
||||
|
||||
log.info( $"Lock {lockId} Create {objId.ToString( "X" )} {obj?.GetType()?.Name} {obj}", cat: te.EventName );
|
||||
//*/
|
||||
}
|
||||
catch( Exception ex )
|
||||
{
|
||||
log.info( $"Lock {lockId} Create 0x{intPtrStr} (Could not get object) [{ex.Message}]", cat: te.EventName );
|
||||
}
|
||||
|
||||
LogGeneric( te, "| Raw: " );
|
||||
|
||||
return;
|
||||
//logDetails = "| Details: ";
|
||||
}
|
||||
else if( te.EventName.StartsWith( "Contention/Start" ) )
|
||||
{
|
||||
// EventName="Contention/Start" ContentionFlags="Managed" LockID="0x000000011D015CB8" AssociatedObjectID="0x00000003504554C0" LockOwnerThreadID="0"
|
||||
// EventName="Contention/Stop" ContentionFlags="Managed" DurationNs="26000"
|
||||
|
||||
var lockId = te.Get<UInt64>( "LockID" );
|
||||
var objId = te.Get<UInt64>( "AssociatedObjectID" );
|
||||
var threadId = te.Get<Int64>( "LockOwnerThreadID" );
|
||||
|
||||
log.info( $"Lock {lockId} {te.Get( "ContentionFlags" )} in thread {threadId} on obj 0x{objId.ToString( "X" )} ", cat: te.EventName );
|
||||
|
||||
LogGeneric( te, "| Raw: " );
|
||||
}
|
||||
else if( te.EventName.StartsWith( "Contention/Stop" ) )
|
||||
{
|
||||
//var lockId = te.Get<int>( "LockID" );
|
||||
//var objId = te.Get<IntPtr>( "AssociatedObjectID" );
|
||||
//var threadId = te.Get<Int64>( "LockOwnerThreadID" );
|
||||
|
||||
log.info( $"Lock {{lockId}} {te.Get( "ContentionFlags" )} Duration {te.Get<double>( "DurationNs" )}ns", cat: te.EventName );
|
||||
|
||||
LogGeneric( te, "| Raw: " );
|
||||
}
|
||||
else if( te.EventName.StartsWith( "AssemblyLoader/" ) || te.EventName.StartsWith( "Loader/" ) )
|
||||
{
|
||||
//AssemblyLoader/Start AssemblyName AssemblyLoadContext RequestingAssemblyLoadContext AssemblyPath RequestingAssembly
|
||||
//AssemblyLoader/Stop AssemblyName AssemblyLoadContext RequestingAssemblyLoadContext AssemblyPath RequestingAssembly Success ResultAssemblyName ResultAssemblyPath Cached
|
||||
//Loader/AssemblyLoad AssemblyID AppDomainID AssemblyFlags FullyQualifiedAssemblyName BindingID
|
||||
//AssemblyLoader/ResolutionAttempted
|
||||
// AssemblyName AssemblyLoadContext Result ResultAssemblyName ResultAssemblyPath Stage ErrorMessage
|
||||
|
||||
//Loader/ModuleLoad ModuleID AssemblyID ModuleFlags ModuleILPath ModuleNativePath ManagedPdbSignature ManagedPdbAge ManagedPdbBuildPath
|
||||
//Loader/DomainModuleLoad ModuleID AssemblyID ModuleFlags ModuleILPath ModuleNativePath AppDomainID
|
||||
|
||||
//AssemblyLoader/KnownPathProbed FilePath Source Result
|
||||
var appDomainId = te.Get( "AppDomainID" );
|
||||
|
||||
var asId = te.Get( "AssemblyID" );
|
||||
var asName = te.Get( "AssemblyName" );
|
||||
var asPath = te.Get( "AssemblyPath" );
|
||||
var asLC = te.Get( "AssemblyLoadContext" );
|
||||
|
||||
var reqAs = te.Get( "RequestingAssembly" );
|
||||
var reqAsLC = te.Get( "RequestingAssemblyLoadContext" );
|
||||
|
||||
var reqAsName = te.Get( "ResultAssemblyName" );
|
||||
var reqAsPath = te.Get( "ResultAssemblyPath" );
|
||||
|
||||
var success = te.Get( "Success" );
|
||||
var cached = te.Get( "Cached" );
|
||||
var errMsg = te.Get( "ErrorMessage" );
|
||||
var stage = te.Get( "Stage" );
|
||||
var result = te.Get( "Result" );
|
||||
var source = te.Get( "Source" );
|
||||
|
||||
var modId = te.Get( "ModuleID" );
|
||||
var modFlags = te.Get( "ModuleFlags" );
|
||||
var modILPath = te.Get( "ModuleILPath" );
|
||||
var modNativePath = te.Get( "ModuleNativePath" );
|
||||
|
||||
var manBuildPath = te.Get( "ManagedPdbBuildPath" );
|
||||
var fqaName = te.Get( "FullyQualifiedAssemblyName" );
|
||||
var bindingId = te.Get( "BindingID" );
|
||||
|
||||
}
|
||||
|
||||
|
||||
|
||||
|
||||
|
||||
//76 CHARACTERS
|
||||
//<Event MSec= "180.2315" PID="35297" PName="Process(35297)" TID="294046"
|
||||
|
||||
LogGeneric( te, logDetails );
|
||||
|
||||
|
||||
|
||||
/*
|
||||
if( eventData.Length > 0 )
|
||||
{
|
||||
Encoding enc = new UnicodeEncoding(false, false, true);
|
||||
var eventDataUtf16 = enc.GetString( eventData );
|
||||
log.debug( $"> {eventDataUtf16}" );
|
||||
}
|
||||
*/
|
||||
}
|
||||
else
|
||||
{
|
||||
/*
|
||||
var payloadNames = te.PayloadNames;
|
||||
var channel = te.Channel;
|
||||
var formattedMsg = te.FormattedMessage;
|
||||
var keywords = te.Keywords;
|
||||
var source = te.Source;
|
||||
var dump = te.Dump();
|
||||
var dynMemberNames = te.GetDynamicMemberNames();
|
||||
var dataStart = te.DataStart;
|
||||
*/
|
||||
|
||||
var eventData = te.EventData();
|
||||
|
||||
//var eventDataStr = eventData.ToString();
|
||||
|
||||
Encoding enc = new UnicodeEncoding( false, false, true );
|
||||
var eventDataUtf16 = enc.GetString( eventData );
|
||||
//var safeEventData = eventDataUtf16.Replace( (char)0, '\n' );
|
||||
|
||||
var arrEventData = eventDataUtf16.Split( (char)0 );
|
||||
var joinedEventData = string.Join( " | ", arrEventData );
|
||||
|
||||
//log.info( $"{te.FormattedMessage}", cat: catIn );
|
||||
log.info( $"{joinedEventData}", cat: catIn );
|
||||
}
|
||||
|
||||
|
||||
};
|
||||
}
|
||||
|
||||
private static ConcurrentDictionary<string, ImmutableHashSet<string>> s_validKeywords = new();
|
||||
|
||||
private static void LogGeneric( TraceEvent te, string logDetails )
|
||||
{
|
||||
var teStr = te.ToString().Replace( "ClrInstanceID=\"0\"", "" );
|
||||
|
||||
/*
|
||||
|
||||
*/
|
||||
|
||||
var startIndex = teStr.IndexOf( "EventName" );
|
||||
|
||||
//log.debug( $"{logDetails} {startIndex} {teStr}", cat: te.EventName );
|
||||
|
||||
var teStrSlice = teStr.AsSpan( startIndex, teStr.Length - ( startIndex + 1 + 1 ) );
|
||||
|
||||
log.debug( $"{logDetails}{teStrSlice}", cat: te.EventName );
|
||||
|
||||
/*
|
||||
try
|
||||
{
|
||||
TraceCallStack? callstack = te.CallStack();
|
||||
//if( callstack != null) log.trace( $"| Callstack: {callstack?.ToString()}" );
|
||||
if( callstack != null )
|
||||
{
|
||||
log.trace( $"| Callstack:" );
|
||||
log.trace( $"| {callstack.Depth}" );
|
||||
log.trace( $"| {callstack.CodeAddress}" );
|
||||
}
|
||||
}
|
||||
catch( Exception ex )
|
||||
{
|
||||
log.debug( $"Caught {ex.Message} while getting the callstack" );
|
||||
}
|
||||
//*/
|
||||
}
|
||||
|
||||
public static void PrintRuntimeGCEvents( int processId )
|
||||
{
|
||||
var providers = new List<EventPipeProvider>()
|
||||
{
|
||||
new EventPipeProvider("Microsoft-Windows-DotNETRuntime",
|
||||
EventLevel.Verbose, (long)(
|
||||
TraceKeywords.GC |
|
||||
TraceKeywords.Contention |
|
||||
TraceKeywords.Debugger |
|
||||
TraceKeywords.Exception |
|
||||
TraceKeywords.GCAllObjectAllocation |
|
||||
TraceKeywords.GCSampledObjectAllocationHigh |
|
||||
TraceKeywords.GCSampledObjectAllocationLow |
|
||||
TraceKeywords.Security |
|
||||
TraceKeywords.Threading |
|
||||
TraceKeywords.Type |
|
||||
TraceKeywords.TypeDiagnostic |
|
||||
TraceKeywords.WaitHandle |
|
||||
TraceKeywords.All
|
||||
) )
|
||||
};
|
||||
|
||||
var client = new DiagnosticsClient( processId );
|
||||
using( EventPipeSession session = client.StartEventPipeSession( providers, false ) )
|
||||
{
|
||||
var source = new EventPipeEventSource( session.EventStream );
|
||||
|
||||
|
||||
source.Clr.GCAllocationTick += OnAllocTick;
|
||||
|
||||
//source.Clr.All += LogCategoryFunc( "clr" );
|
||||
|
||||
//source.Kernel.All += LogCategoryFunc( "kernel" );
|
||||
|
||||
// Doesnt seem to be too interesting.
|
||||
//source.Dynamic.All += LogCategoryFunc( "dynamic" );
|
||||
|
||||
|
||||
try
|
||||
{
|
||||
source.Process();
|
||||
}
|
||||
catch( Exception e )
|
||||
{
|
||||
Console.WriteLine( "Error encountered while processing events" );
|
||||
Console.WriteLine( e.ToString() );
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
private static void OnAllocTick( GCAllocationTickTraceData data )
|
||||
{
|
||||
}
|
||||
}
|
||||
|
||||
675
archive/logging/Tracing.cs
Normal file
675
archive/logging/Tracing.cs
Normal file
@ -0,0 +1,675 @@
|
||||
using Microsoft.Diagnostics.Symbols;
|
||||
using Microsoft.Diagnostics.Tracing;
|
||||
using Microsoft.Diagnostics.Tracing.Etlx;
|
||||
using Microsoft.Diagnostics.Tracing.Parsers;
|
||||
using Microsoft.Diagnostics.Tracing.Parsers.Clr;
|
||||
using Microsoft.Diagnostics.Tracing.Parsers.Kernel;
|
||||
using Microsoft.Diagnostics.Tracing.Session;
|
||||
using System;
|
||||
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
|
||||
{
|
||||
/// <summary>
|
||||
/// 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.
|
||||
/// </summary>
|
||||
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<EventPipeProvider> _customProviders = new();
|
||||
|
||||
private Action<TraceEvent> _userCallback;
|
||||
private EventPipeSession _session;
|
||||
private TraceEventSource _traceLogSource; /// CHANGED
|
||||
private Task _processingTask;
|
||||
|
||||
|
||||
private Timer _timer;
|
||||
|
||||
public EventPipeTraceMonitor( int processId )
|
||||
{
|
||||
_pid = processId;
|
||||
}
|
||||
|
||||
// ####################################################################
|
||||
// Builder Configuration Methods
|
||||
// ####################################################################
|
||||
|
||||
public EventPipeTraceMonitor WithDuration( int seconds )
|
||||
{
|
||||
_durationSec = seconds;
|
||||
return this;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Adds a custom EventPipeProvider.
|
||||
/// </summary>
|
||||
public EventPipeTraceMonitor AddProvider( EventPipeProvider provider )
|
||||
{
|
||||
_customProviders.Add( provider );
|
||||
return this;
|
||||
}
|
||||
|
||||
// ####################################################################
|
||||
// Event Selection Methods
|
||||
// ####################################################################
|
||||
|
||||
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;
|
||||
}
|
||||
|
||||
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;
|
||||
}
|
||||
|
||||
// ####################################################################
|
||||
// Core Execution Methods
|
||||
// ####################################################################
|
||||
|
||||
public void Start( Action<TraceEvent> onEventCallback )
|
||||
{
|
||||
_userCallback = onEventCallback;
|
||||
var providers = new List<EventPipeProvider>( _customProviders );
|
||||
|
||||
|
||||
|
||||
|
||||
|
||||
if( _clrKeywords != ClrTraceEventParser.Keywords.None )
|
||||
{
|
||||
// Add the main CLR provider
|
||||
providers.Add( new EventPipeProvider(
|
||||
"Microsoft-Windows-DotNETRuntime",
|
||||
EventLevel.Informational,
|
||||
(long)_clrKeywords ) );
|
||||
}
|
||||
|
||||
if( _monitorCpu )
|
||||
{
|
||||
// Add the CPU sampler provider
|
||||
providers.Add( new EventPipeProvider(
|
||||
"Microsoft-DotNETCore-SampleProfiler",
|
||||
EventLevel.Informational ) );
|
||||
}
|
||||
|
||||
|
||||
|
||||
|
||||
|
||||
|
||||
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();
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Internal event handler.
|
||||
/// </summary>
|
||||
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 );
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// 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.
|
||||
/// </summary>
|
||||
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<Action<TraceLogEventSource>> _eventRegistrars = new();
|
||||
private Action<TraceEvent> _userCallback;
|
||||
private SymbolReader _symbolReader;
|
||||
private readonly object _symbolReaderLock = new();
|
||||
private TextWriter _symbolLog = new StringWriter();
|
||||
private Timer _timer;
|
||||
|
||||
// ####################################################################
|
||||
// Builder Configuration Methods
|
||||
// ####################################################################
|
||||
|
||||
/// <summary>
|
||||
/// Sets the monitoring duration in seconds.
|
||||
/// </summary>
|
||||
public RealTimeTraceMonitor WithDuration( int seconds )
|
||||
{
|
||||
_durationSec = seconds;
|
||||
return this;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Filters events to only include those from a process whose name contains this string.
|
||||
/// </summary>
|
||||
public RealTimeTraceMonitor FilterByProcess( string processName )
|
||||
{
|
||||
_processFilter = processName;
|
||||
return this;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Provides a TextWriter for detailed symbol lookup messages.
|
||||
/// </summary>
|
||||
public RealTimeTraceMonitor WithSymbolLog( TextWriter logWriter )
|
||||
{
|
||||
_symbolLog = logWriter;
|
||||
return this;
|
||||
}
|
||||
|
||||
// ####################################################################
|
||||
// Event Selection Methods
|
||||
// ####################################################################
|
||||
|
||||
/// <summary>
|
||||
/// Enables monitoring for CLR Exceptions (ExceptionStart).
|
||||
/// Automatically enables JIT, Loader, and Stack keywords required for symbol resolution.
|
||||
/// </summary>
|
||||
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;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Enables monitoring for CLR Module Loads (LoaderModuleLoad).
|
||||
/// Automatically enables JIT, Loader, and Stack keywords.
|
||||
/// </summary>
|
||||
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;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Enables monitoring for CPU Samples (PerfInfoSample).
|
||||
/// </summary>
|
||||
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;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Enables monitoring for arbitrary Kernel events.
|
||||
/// </summary>
|
||||
/// <param name="events">Kernel keywords to enable.</param>
|
||||
/// <param name="stackEvents">Keywords to collect stacks for.</param>
|
||||
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;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Enables monitoring for arbitrary CLR events.
|
||||
/// Note: For complex events, prefer the specific Monitor* methods.
|
||||
/// </summary>
|
||||
/// <param name="events">CLR keywords to enable.</param>
|
||||
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
|
||||
// ####################################################################
|
||||
|
||||
/// <summary>
|
||||
/// Starts the monitoring session and blocks until the duration expires or Ctrl+C is pressed.
|
||||
/// </summary>
|
||||
/// <param name="onEventCallback">The callback to execute for each filtered event.</param>
|
||||
public void Start( Action<TraceEvent> 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;
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Stops the monitoring session.
|
||||
/// </summary>
|
||||
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 );
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Primary event handler.
|
||||
/// This method is called from multiple threads and must be thread-safe.
|
||||
/// </summary>
|
||||
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 );
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Resolves native symbols for a given call stack.
|
||||
/// This method locks the SymbolReader, as it is not thread-safe.
|
||||
/// </summary>
|
||||
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;
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Example implementation of the RealTimeTraceMonitor utility.
|
||||
/// </summary>
|
||||
internal class TraceLogMonitor
|
||||
{
|
||||
public static void Run()
|
||||
{
|
||||
log.info( "******************** RealTimeTraceLog DEMO ********************" );
|
||||
|
||||
// Define a thread-safe callback to process events
|
||||
Action<TraceEvent> 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 ) { }
|
||||
}
|
||||
}
|
||||
}
|
||||
1246
logging/Log.cs
1246
logging/Log.cs
File diff suppressed because it is too large
Load Diff
Loading…
Reference in New Issue
Block a user