sharplib/logging/Log.cs
Marc Hernandez 404789d87c feat: Add explicit transaction class/ID and split functionality into threaded vs action
x) Added enum for CommitResults
x) Created interface IID<TS>
x) Implemented DB class with lock, objects, committed lists
x) Updated lookup and checkout methods in DB class
x) Added TxStates enum and implemented Tx class with checkout, add, dispose methods
x) Implemented commit method in DB class to handle transactions efficiently
2024-06-05 15:02:21 -07:00

868 lines
21 KiB
C#

using System;
using System.IO;
using System.Diagnostics;
using System.Collections;
using System.Runtime.CompilerServices;
using System.Collections.Generic;
using System.Collections.Immutable;
using System.Reflection;
using System.Collections.Concurrent;
using System.Linq;
using System.Threading;
using System.Security.Cryptography.X509Certificates;
using lib.Net;
using System.Dynamic;
using System.Xml.Schema;
using Microsoft.CodeAnalysis.CSharp.Syntax;
//using System.Threading.Tasks;
#nullable enable
/*
T O D O :
x) Refactor various logs in order to do automagic structured logging
ref: https://learn.microsoft.com/en-us/dotnet/csharp/whats-new/tutorials/interpolated-string-handler
D O N E:
N O T D O I N G :
*/
public record struct Value<T>( T _val = default, string _exp = "" )
{
static public Value<T> Get<T>( T v,
[CallerArgumentExpression("fn")]
string dbgExp = ""
)
{
return new( v, dbgExp );
}
}
public struct SourceLoc
{
readonly string _reason = "";
readonly string _dbgName = "";
readonly string _dbgPath = "";
readonly int _dbgLine = -1;
public SourceLoc( string reason, string dbgName, string dbgPath, int dbgLine )
{
_reason = reason;
_dbgName = dbgName;
_dbgPath = dbgPath;
_dbgLine = dbgLine;
}
static public SourceLoc Record(
string reason = "",
[CallerMemberName] string dbgName = "",
[CallerFilePath] string dbgPath = "",
[CallerLineNumber] int dbgLine = 0
)
{
return new SourceLoc( reason, dbgName, dbgPath, dbgLine );
}
}
static public class log
{
//static
static log()
{
log.high( $"Starting tracers" );
/*
{
var start = new ThreadStart( StartGCWatcher );
var thread = new Thread( start );
thread.Priority = ThreadPriority.BelowNormal;
thread.Name = $"Logging";
thread.Start();
}
// */
//log.info( $"Tracing.Program.CreateTracingSession" );
//var task = log.call( Tracing.Program.CreateTracingSession( false, true, 64 ) );
//*
log.info( $"Tracing.MemoryPipe" );
var memoryPipe = log.call( () => new Tracing.MemoryPipe() );
//var pipeTask = log.call( () => memoryPipe.StartAsync( true ) );
//*/
/*
{
var start = new ThreadStart( StartTracing );
var thread = new Thread( start );
thread.Priority = ThreadPriority.BelowNormal;
thread.Name = $"Logging";
thread.Start();
}
// */
}
static void StartGCWatcher()
{
while( !s_running )
{
Thread.Sleep( 10 );
}
var processId = Process.GetCurrentProcess().Id;
LogGC.PrintRuntimeGCEvents( processId );
}
static void StartTracing()
{
while( !s_running )
{
Thread.Sleep( 10 );
}
Tracing.TraceLogMonitor.Run();
}
static public Value<T> Value<T>( T val,
[CallerArgumentExpression("val")]
string dbgExp = ""
)
{
return new( val, dbgExp );
}
[Flags]
public enum LogType
{
Invalid = 0,
Trace = 1,
Debug = 2,
Info = 3,
High = 4,
Warn = 5,
Error = 6,
Fatal = 7,
Time = 64,
Raw = 65,
}
[Flags]
public enum Endpoints
{
None = 0,
File = 1 << 0,
Console = 1 << 1,
All = File | Console,
}
public struct LogEvent
{
public DateTime Time;
public LogType LogType;
public string Msg;
public string Path;
public int Line;
public string Member;
public string Exp;
public string Cat;
public object? Obj;
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 )
{
//Cache the automatic category names
// R A R E and S L O W and S A F E
if( string.IsNullOrEmpty( cat ) )
{
var pathHash = path.GetHashCode();
if( s_shortname.TryGetValue( pathHash, out var autoCat ) )
{
cat = autoCat;
}
else
{
var pathPieces = path.Split( '\\' );
if( pathPieces.Length < 2 )
{
pathPieces = path.Split( '/' );
}
var lastDir = pathPieces[pathPieces.Length - 2];
ImmutableInterlocked.AddOrUpdate( ref s_shortname, pathHash, lastDir, ( key, value ) => { return lastDir; } );
cat = lastDir;
}
}
Time = DateTime.Now;
LogType = logType;
Msg = msg;
Path = path;
Line = line;
Member = member;
Cat = cat;
Exp = exp;
Obj = obj;
}
}
static LogEvent CreateLogEvent( LogType logType, string msg, string cat, object? obj, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", string exp = "" )
{
var logEvent = new LogEvent( logType, msg, path, line, member, cat, exp, obj );
return logEvent;
}
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 );
}
static public void create( string filename, Endpoints endpoints )
{
startup( filename, endpoints );
}
static public void destroy()
{
string msg = "==============================================================================\nLogfile shutdown at " + DateTime.Now.ToString();
var evt = CreateLogEvent( LogType.Info, msg, "System", null );
s_events.Enqueue( evt );
stop();
}
static internal ConcurrentQueue<LogEvent> s_events = new ConcurrentQueue<LogEvent>();
static private Thread s_thread = Thread.CurrentThread;
/*
static public Log log
{
get
{
return s_log;
}
}
*/
static string s_cwd = Directory.GetCurrentDirectory();
static int s_cwdLength = s_cwd.Length;
static ImmutableDictionary<int, string> s_files = ImmutableDictionary<int, string>.Empty;
#region Util
static public string whatFile( string path )
{
var file = "";
var pathHash = path.GetHashCode();
if( s_files.TryGetValue( pathHash, out var autoCat ) )
{
file = autoCat;
}
else
{
var pathPieces = path.Split( '\\' );
if( pathPieces.Length < 2 )
{
pathPieces = path.Split( '/' );
}
var lastDir = pathPieces[pathPieces.Length - 1];
ImmutableInterlocked.AddOrUpdate( ref s_files, pathHash, lastDir, ( key, value ) => { return lastDir; } );
file = lastDir;
}
return file;
}
static public string relativePath( string fullPath )
{
if( fullPath.Length < s_cwdLength )
return fullPath;
var rel = fullPath.Substring( s_cwdLength + 1 );
return rel;
}
static public string thisFilePath( [CallerFilePath] string path = "" )
{
return relativePath( path );
}
#endregion // Util
#region Forwards
static public T call<T>( Func<T> func, [CallerMemberName] string dbgName = "", [CallerFilePath] string dbgPath = "", [CallerLineNumber] int dbgLine = -1, [CallerArgumentExpression("func")] string dbgExp = "" )
{
log.info( $"Calling {dbgExp}" );
var val = func();
log.info( $"| Got {val}" );
return val;
}
static public T call<T>( T val, [CallerMemberName] string dbgName = "", [CallerFilePath] string dbgPath = "", [CallerLineNumber] int dbgLine = -1, [CallerArgumentExpression("val")] string dbgExp = "" )
{
log.info( $"Called {dbgExp} Got: {val}" );
return val;
}
static public void call( Action func, [CallerMemberName] string dbgName = "", [CallerFilePath] string dbgPath = "", [CallerLineNumber] int dbgLine = -1, [CallerArgumentExpression("func")] string dbgExp = "" )
{
log.info( $"Calling {dbgExp}" );
func();
log.info( $"| Done" );
}
static public void fatal( string msg, string cat = "", object? obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("msg")] string dbgExp = "" )
{
logBase( msg, LogType.Fatal, path, line, member, cat, dbgExp, obj );
}
static public void error( string msg, string cat = "", object? obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("msg")] string dbgExp = "" )
{
logBase( msg, LogType.Error, path, line, member, cat, dbgExp, obj );
}
static public void warn( string msg, string cat = "", object? obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("msg")] string dbgExp = "" )
{
logBase( msg, LogType.Warn, path, line, member, cat, dbgExp, obj );
}
static public void high( string msg, string cat = "", object? obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("msg")] string dbgExp = "" )
{
logBase( msg, LogType.High, path, line, member, cat, dbgExp, obj );
}
static public void info( string msg, string cat = "", object? obj = null,
[CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("msg")] string dbgExp = "" )
{
logBase( msg, LogType.Info, path, line, member, cat, dbgExp, obj );
}
static public void debug( string msg, string cat = "", object? obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("msg")] string dbgExp = "" )
{
logBase( msg, LogType.Debug, path, line, member, cat, dbgExp, obj );
}
static public void trace( string msg, string cat = "", object? obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("msg")] string dbgExp = "" )
{
logBase( msg, LogType.Trace, path, line, member, cat, dbgExp, obj );
}
static public void inf_valueo<A>( string msg, Value<A> v1, string cat = "" )
{
}
static public void info<A>( string msg, A a, string cat = "", [CallerArgumentExpression("a")] string dbgExpA = "" )
{
}
static public void info( string msg, object a, object b, string cat = "", [CallerArgumentExpression("a")] string dbgExpA = "", [CallerArgumentExpression("a")] string dbgExpB = "" )
{
}
#endregion
#region Helpers
static public void logProps( object obj, string header, LogType type = LogType.Debug, string cat = "", string prefix = "", [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "", [CallerArgumentExpression("obj")] string dbgExpObj = "" )
{
var list = refl.GetAllProperties( obj.GetType() );
lock( s_lock )
{
var evt = new LogEvent( type, header, path, line, member, cat, dbgExpObj, obj );
{
s_events.Enqueue( evt );
foreach( var pi in list )
{
try
{
var v = pi.GetValue( obj );
logBase( $"{prefix}{pi.Name} = {v}", type, path, line, member, dbgExpObj, cat );
}
catch( Exception ex )
{
logBase( $"Exception processing {pi.Name} {ex.Message}", LogType.Error, path, line, member, cat, dbgExpObj, obj);
}
}
}
}
}
//This might seem a little odd, but the intent is that usually you wont need to set notExpectedValue.
static public void expected<T>( T value, string falseString, string trueString = "", T? notExpectedValue = default( T ) )
{
if( !object.Equals( value, notExpectedValue ) )
{
log.debug( $"Properly got {value}{trueString}" );
}
else
{
log.warn( $"Got {notExpectedValue} instead of {value}{falseString}" );
}
}
#endregion
static object s_lock = new object();
static public LogEvent logCreateEvent( string msg, LogType type = LogType.Debug, string path = "", int line = -1, string member = "", string cat = "unk", string exp = "", object? obj = null )
{
LogEvent evt = new LogEvent( type, msg, path, line, member, cat, exp, obj );
return evt;
}
static public void logBase( string msg, LogType type = LogType.Debug, string path = "", int line = -1, string member = "", string cat = "unk", string exp = "", object? obj = null )
{
var evt = logCreateEvent( msg, type, path, line, member, cat, exp );
s_events.Enqueue( evt );
}
static Endpoints s_endpoints = Endpoints.Console;
static int s_catWidth = 14;
static void startup( string filename, Endpoints endpoints )
{
if( string.IsNullOrWhiteSpace( filename ) )
{
return;
}
s_startTime = DateTime.Now;
s_cwd = Directory.GetCurrentDirectory();
s_cwdLength = s_cwd.Length;
s_endpoints = endpoints;
var dir = Path.GetDirectoryName( filename );
if( dir?.Length > 0 )
{
Directory.CreateDirectory( dir );
}
s_stream = new FileStream( filename, FileMode.Append, FileAccess.Write );
s_writer = new StreamWriter( s_stream );
s_errorStream = new FileStream( filename + ".error", FileMode.Append, FileAccess.Write );
s_errorWriter = new StreamWriter( s_errorStream );
{
var time = DateTime.Now;
// Header for this run
var blankLine = new LogEvent( LogType.Raw, $"", "", 0, "", "lib.time", "", null );
var beginLine = new LogEvent( LogType.Raw, $"Begin B E G I N ******************************************************************************************************************", "", 0, "", "lib.time", "", null );
var timeLine = new LogEvent( LogType.Raw, $"D A T E {time.Year}/{time.Month.ToString("00")}/{time.Day.ToString("00")} T I M E {time.Hour.ToString("00")}:{time.Minute.ToString("00")}:{time.Second.ToString("00")}.{time.Millisecond.ToString("000")}{time.Microsecond.ToString("000")}", "", 0, "", "lib.time", "", null );
//writeToAll( endLine );
writeToAll( blankLine );
writeToAll( blankLine );
writeToAll( beginLine );
writeToAll( blankLine );
writeToAll( timeLine );
writeToAll( blankLine );
}
LogEvent msgStartupBegin = new LogEvent( LogType.Info, $"startup BEGIN", "", 0, "", "log.startup", "", null );
writeToAll( msgStartupBegin );
LogEvent msgFilename = new LogEvent( LogType.Info, $"Logging in {filename}", "", 0, "", "log.startup", "", null );
writeToAll( msgFilename );
var start = new ThreadStart( run );
s_thread = new Thread( start );
s_thread.Priority = ThreadPriority.BelowNormal;
s_thread.Name = $"Logging";
s_thread.Start();
//info( $"Logging in {filename}" );
LogGC.RegisterObjectId( s_lock );
//Debug.Listeners.Add( this );
//var evt = CreateLogEvent( LogType.Info, $"startup", "System", null );
//s_events.Enqueue( evt );
/*
if( (endpoints & Endpoints.Console) == Endpoints.Console )
{
addDelegate(WriteToConsole);
}
*/
//LogEvent msgStartupBegin = new LogEvent( LogType.Info, $"startup END", "", 0, "", "lib.time", "", null );
//writeToAll( msgStartupBegin );
info( $"startup END", cat: "log.startup" );
}
static bool s_running = true;
static void run()
{
while( s_running )
{
while( s_events.TryDequeue( out var evt ) )
{
writeToAll( evt );
}
// TODO PERF Replace this with a semaphore/mutex
Thread.Sleep( 0 );
}
var endLine = new LogEvent( LogType.Raw, $"End E N D ******************************************************************************************************************", "", 0, "", "lib.time", "", null );
writeToAll( endLine );
}
public static void stop()
{
if( !s_running ) return;
s_running = false;
while( s_thread.IsAlive )
{
Thread.Sleep( 0 );
}
s_writer?.Close();
s_stream?.Close();
s_errorWriter?.Close();
s_errorStream?.Close();
}
static public void addDelegate( Log_delegate cb )
{
s_delegates.Add( cb );
}
public static char getSymbol( LogType type )
{
switch( type )
{
case LogType.Trace: return ' ';
case LogType.Debug: return ' ';
case LogType.Info: return ' ';
case LogType.High: return '+';
case LogType.Warn: return '+';
case LogType.Error: return '*';
case LogType.Fatal: return '*';
default: return '?';
}
}
private static void setConsoleColor( log.LogEvent evt )
{
switch( evt.LogType )
{
case log.LogType.Trace:
Console.ForegroundColor = ConsoleColor.DarkGray;
break;
case log.LogType.Debug:
Console.ForegroundColor = ConsoleColor.Gray;
break;
case log.LogType.Info:
Console.ForegroundColor = ConsoleColor.DarkGreen;
break;
case log.LogType.High:
Console.ForegroundColor = ConsoleColor.Cyan;
break;
case log.LogType.Warn:
Console.ForegroundColor = ConsoleColor.Yellow;
break;
case log.LogType.Error:
Console.ForegroundColor = ConsoleColor.DarkRed;
Console.BackgroundColor = ConsoleColor.DarkGray;
break;
case log.LogType.Fatal:
Console.ForegroundColor = ConsoleColor.Red;
Console.BackgroundColor = ConsoleColor.DarkGray;
break;
case log.LogType.Invalid:
case log.LogType.Time:
case log.LogType.Raw:
Console.ForegroundColor = ConsoleColor.Red;
break;
}
}
static private DateTime s_startTime = DateTime.MinValue;
static private int s_lastDisplaySeconds = -1;
static private int s_lastSecond = -1;
static private string s_timeHeader = " ";
static public string headerPrint( LogEvent evt )
{
if( evt.LogType != LogType.Raw )
{
var span = evt.Time - s_startTime;
char sym = getSymbol( evt.LogType );
var truncatedCat = evt.Cat.Substring( 0, Math.Min( s_catWidth, evt.Cat.Length ) );
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 );
return msgHdr;
}
else
{
return "";
}
}
static public string headerFile( LogEvent evt )
{
if( evt.LogType != LogType.Raw )
{
var span = evt.Time - s_startTime;
char sym = getSymbol( evt.LogType );
var truncatedCat = evt.Cat.Substring( 0, Math.Min( s_catWidth, evt.Cat.Length ) );
//Dont really need the year-month-day frankly.
//var timeHdr = $"{evt.Time.Year}-{evt.Time.Month.ToString("00")}-{evt.Time.Day.ToString("00")} {evt.Time.Hour.ToString("00")}:{evt.Time.Minute.ToString("00")}:{evt.Time.Second.ToString("00")}.{evt.Time.Millisecond.ToString("000")}{evt.Time.Microsecond.ToString("000")}";
var timeHdr = $"{evt.Time.Hour.ToString("00")}:{evt.Time.Minute.ToString("00")}:{evt.Time.Second.ToString("00")}.{evt.Time.Millisecond.ToString("000")}{evt.Time.Microsecond.ToString("000")}";
var msgHdr = string.Format( $"{timeHdr} | {{0,-{s_catWidth}}}{{1}}| ", truncatedCat, sym );
return msgHdr;
}
else
{
return "";
}
}
static public string msgPrint( LogEvent evt )
{
var msgHdr = headerPrint( evt );
string finalLine = $"{msgHdr}{evt.Msg}";
return finalLine;
}
static public string msgFile( LogEvent evt )
{
var msgHdr = headerFile( evt );
string finalLine = $"{msgHdr}{evt.Msg}";
return finalLine;
}
static private void writeSpecialEvent( LogEvent evt )
{
if( ( s_endpoints & Endpoints.Console ) == Endpoints.Console )
{
//setConsoleColor( evt );
//Console.WriteLine( $"{evt.Time.ToShortTimeString()}" );
//Console.ResetColor();
}
foreach( Log_delegate cb in s_delegates )
{
cb( evt );
}
}
static private void writeToAll( LogEvent evt )
{
try
{
#region Time
var span = evt.Time - s_startTime;
var curSeconds = (int)span.TotalSeconds;
if( curSeconds - s_lastDisplaySeconds > 10 )
{
s_lastDisplaySeconds = curSeconds;
var minuteEvt = new LogEvent( LogType.Raw, $"T I M E ==> {evt.Time.Hour.ToString("00")}:{evt.Time.Minute.ToString("00")}:{evt.Time.Second.ToString("00")}.{evt.Time.Millisecond.ToString("000")} : {evt.Time.ToShortDateString()}", "", 0, "", "lib.time", "", null );
minuteEvt.Time = evt.Time;
writeSpecialEvent( minuteEvt );
}
if( evt.LogType != LogType.Raw )
{
var curSecond = (int)span.TotalSeconds;
if( s_lastSecond == curSecond )
{
s_timeHeader = " ";
}
else
{
s_timeHeader = "*";
s_lastSecond = curSecond;
}
}
#endregion
#region Write
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 );
s_writer?.WriteLine( line );
}
if( ( finalEndpoints & Endpoints.Console ) == Endpoints.Console )
{
var line = msgPrint( evt );
setConsoleColor( evt );
Console.WriteLine( line );
Console.ResetColor();
}
//Debug.WriteLine( finalLine );
s_writer?.Flush();
foreach( Log_delegate cb in s_delegates )
{
cb( evt );
}
#endregion
}
catch( Exception ex )
{
#region Catch
Console.WriteLine( "EXCEPTION DURING LOGGING" );
Console.WriteLine( "EXCEPTION DURING LOGGING" );
Console.WriteLine( "EXCEPTION DURING LOGGING" );
Console.WriteLine( "EXCEPTION DURING LOGGING" );
Console.WriteLine( "EXCEPTION DURING LOGGING" );
Console.WriteLine( $"Exception {ex}" );
Debug.WriteLine( "EXCEPTION DURING LOGGING" );
Debug.WriteLine( "EXCEPTION DURING LOGGING" );
Debug.WriteLine( "EXCEPTION DURING LOGGING" );
Debug.WriteLine( "EXCEPTION DURING LOGGING" );
Debug.WriteLine( "EXCEPTION DURING LOGGING" );
Debug.WriteLine( $"Exception {ex}" );
#endregion
}
}
public static void WriteToConsole( LogEvent evt )
{
char sym = getSymbol( evt.LogType );
var truncatedCat = evt.Cat.Substring( 0, Math.Min( 8, evt.Cat.Length ) );
string finalLine = string.Format( "{0,-8}{1}| {2}", truncatedCat, sym, evt.Msg );
Console.WriteLine( finalLine );
}
private static Stream? s_stream;
private static StreamWriter? s_writer;
private static Stream? s_errorStream;
private static StreamWriter? s_errorWriter;
private static ArrayList s_delegates = new ArrayList();
}