Update logging and event handling in GC.cs and Log.cs

x) Added new event handling for runtime garbage collection events
x) Implemented logging endpoints for different categories
x) Improved object creation handling based on type constructors
This commit is contained in:
Marc Hernandez 2024-05-27 16:47:39 -07:00
parent 32d6c29443
commit a62724bf67
3 changed files with 170 additions and 37 deletions

View File

@ -1,53 +1,162 @@
using Microsoft.Diagnostics.NETCore.Client; using Microsoft.Diagnostics.NETCore.Client;
using Microsoft.Diagnostics.Tracing; using Microsoft.Diagnostics.Tracing;
using Microsoft.Diagnostics.Tracing.Etlx;
using Microsoft.Diagnostics.Tracing.EventPipe; using Microsoft.Diagnostics.Tracing.EventPipe;
using Microsoft.Diagnostics.Tracing.Parsers; using Microsoft.Diagnostics.Tracing.Parsers;
using System; using System;
using System.Collections.Generic; using System.Collections.Generic;
using System.Collections.Immutable; using System.Collections.Immutable;
using System.Diagnostics.Tracing; using System.Diagnostics.Tracing;
using System.Text;
using TraceKeywords = Microsoft.Diagnostics.Tracing.Parsers.ClrTraceEventParser.Keywords;
public class RuntimeGCEventsPrinter public class RuntimeGCEventsPrinter
{ {
public static void PrintRuntimeGCEvents(int processId) static ImmutableHashSet<string> blacklist;
{ static ImmutableHashSet<string> stacklist;
var providers = new List<EventPipeProvider>()
{
new EventPipeProvider("Microsoft-Windows-DotNETRuntime",
EventLevel.Informational, (long)ClrTraceEventParser.Keywords.Default)
};
var client = new DiagnosticsClient(processId); static RuntimeGCEventsPrinter()
using (EventPipeSession session = client.StartEventPipeSession(providers, false)) {
{ blacklist = ImmutableHashSet.Create(
var source = new EventPipeEventSource(session.EventStream); "Method/ILToNativeMap",
"GC/BulkMovedObjectRanges",
"GC/BulkSurvivingObjectRanges",
"GC/FinalizeObject",
"Type/BulkType",
"GC/SetGCHandle",
"GC/DestoryGCHandle",
"TypeLoad/Start",
"Method/R2RGetEntryPointStart",
"Method/MethodDetails",
"Method/MemoryAllocatedForJitCode"
);
stacklist = ImmutableHashSet.Create( "{TEST_ITEM}" );
var blacklist = ImmutableHashSet.Create( "Method/ILToNativeMap", "GC/BulkMovedObjectRanges", "GC/BulkSurvivingObjectRanges" ); log.logEndpointForCategory( "Method/MemoryAllocatedForJitCode", log.Endpoints.File );
log.logEndpointForCategory( "TypeLoad/Stop", log.Endpoints.File );
log.logEndpointForCategory( "GC/BulkRootStaticVar", log.Endpoints.File );
log.logEndpointForCategory( "GC/BulkNode", log.Endpoints.File );
log.logEndpointForCategory( "GC/BulkRootStaticVar", log.Endpoints.File );
var fnFilter = (TraceEvent te) => { }
//Console.WriteLine(obj.ToString());
if( blacklist.Contains( te.EventName ) ) return;
log.info( $"{te}", cat: "clr" ); public static Action<TraceEvent> LogCategoryFunc( string catIn )
{
return ( TraceEvent te ) =>
{
var cat = catIn;
}; if( blacklist.Contains( te.EventName )) return;
source.Clr.All += fnFilter; {
var methodBeingCompiledNamespace = te.PayloadStringByName("MethodBeingCompiledNamespace") ?? "";
if( ( methodBeingCompiledNamespace.StartsWith( "Microsoft" ) || methodBeingCompiledNamespace.StartsWith( "System" ) ) ) return;
}
source.Kernel.All += fnFilter; {
var methodNamespace = te.PayloadStringByName("MethodNamespace") ?? "";
if( ( methodNamespace.StartsWith( "Microsoft" ) || methodNamespace.StartsWith( "System" ) ) ) return;
}
source.Dynamic.All += fnFilter; {
var ns = te.PayloadStringByName("TypeName") ?? "";
if( ( ns.StartsWith( "Microsoft" ) || ns.StartsWith( "System" ) ) ) return;
}
if( !te.EventName.StartsWith( "EventID") )
{
//var eventData = te.EventData();
log.info( $"{te}", cat: te.EventName );
/*
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 );
}
try };
{ }
source.Process();
}
catch (Exception e) public static void PrintRuntimeGCEvents( int processId )
{ {
Console.WriteLine("Error encountered while processing events"); var providers = new List<EventPipeProvider>()
Console.WriteLine(e.ToString()); {
} 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.All += LogCategoryFunc( "clr" );
source.Kernel.All += LogCategoryFunc( "kernel" );
source.Dynamic.All += LogCategoryFunc( "dynamic" );
try
{
source.Process();
}
catch( Exception e )
{
Console.WriteLine( "Error encountered while processing events" );
Console.WriteLine( e.ToString() );
}
}
}
} }

View File

@ -13,6 +13,7 @@ using System.Security.Cryptography.X509Certificates;
using lib.Net; using lib.Net;
using System.Dynamic; using System.Dynamic;
using System.Xml.Schema; using System.Xml.Schema;
using Microsoft.CodeAnalysis.CSharp.Syntax;
//using System.Threading.Tasks; //using System.Threading.Tasks;
#nullable enable #nullable enable
@ -179,6 +180,10 @@ static public class log
static ImmutableDictionary<int, string> s_shortname = ImmutableDictionary<int, string>.Empty; static ImmutableDictionary<int, string> s_shortname = ImmutableDictionary<int, string>.Empty;
public LogEvent( LogType logType, string msg, string path, int line, string member, string cat, string exp, object? obj ) public LogEvent( LogType logType, string msg, string path, int line, string member, string cat, string exp, object? obj )
{ {
@ -231,6 +236,13 @@ static public class log
public delegate void Log_delegate( LogEvent evt ); public delegate void Log_delegate( LogEvent evt );
static ImmutableDictionary<string, Endpoints> s_logEPforCat = ImmutableDictionary<string, Endpoints>.Empty;
static public void logEndpointForCategory( string cat, Endpoints ep )
{
ImmutableInterlocked.AddOrUpdate( ref s_logEPforCat, cat, ep, (k, v) => ep );
}
@ -622,7 +634,7 @@ static public class log
var truncatedCat = evt.Cat.Substring( 0, Math.Min( s_catWidth, evt.Cat.Length ) ); var truncatedCat = evt.Cat.Substring( 0, Math.Min( s_catWidth, evt.Cat.Length ) );
var timeHdr = $"{s_timeHeader}{span.Seconds.ToString("D2")}.{span.Milliseconds.ToString("000")}"; var timeHdr = $"{s_timeHeader}{((int)span.TotalMinutes).ToString("000")}:{span.Seconds.ToString("D2")}.{span.Milliseconds.ToString("000")}";
var msgHdr = string.Format( $"{timeHdr} | {{0,-{s_catWidth}}}{{1}}| ", truncatedCat, sym ); var msgHdr = string.Format( $"{timeHdr} | {{0,-{s_catWidth}}}{{1}}| ", truncatedCat, sym );
@ -729,13 +741,16 @@ static public class log
#region Write #region Write
if( ( s_endpoints & Endpoints.File ) == Endpoints.File )
var finalEndpoints = s_logEPforCat.TryGetValue( evt.Cat, out var ep ) ? ep | s_endpoints : s_endpoints;
if( ( finalEndpoints & Endpoints.File ) == Endpoints.File )
{ {
var line = msgFile( evt ); var line = msgFile( evt );
s_writer?.WriteLine( line ); s_writer?.WriteLine( line );
} }
if( ( s_endpoints & Endpoints.Console ) == Endpoints.Console ) if( ( finalEndpoints & Endpoints.Console ) == Endpoints.Console )
{ {
var line = msgPrint( evt ); var line = msgPrint( evt );
setConsoleColor( evt ); setConsoleColor( evt );

View File

@ -975,10 +975,19 @@ namespace lib
try try
{ {
if( _cfg.VerboseLogging ) log.info( $"Activator.CreateInstance" ); if( _cfg.VerboseLogging ) log.info( $"For {type.Name} check for constructors" );
//Trying the nice way to creat objects first. var cons = type.GetConstructor( Type.EmptyTypes );
obj = Activator.CreateInstance( type ); if( cons != null)
{
if( _cfg.VerboseLogging ) log.info( $"Activator.CreateInstance" );
obj = Activator.CreateInstance( type );
}
else
{
log.debug( $"For {type.Name} use GetUninitializedObject" );
obj = System.Runtime.Serialization.FormatterServices.GetUninitializedObject( type );
}
if( _cfg.VerboseLogging ) log.info( $"Got obj {obj?.ToString()}" ); if( _cfg.VerboseLogging ) log.info( $"Got obj {obj?.ToString()}" );
} }