Merge branch 'mh/ft/2-fix-time-display-for-logging' into mh/dev

imm/iu.cs

@@ -11,6 +11,7 @@ using imm;
 using System;
 using System.Runtime.CompilerServices;
 
+
 static public class iu
 {
 	//This can handle both Timed and Recorded

logging/Log.cs

@@ -10,6 +10,7 @@ using System.Collections.Concurrent;
 using System.Linq;
 using System.Threading;
 using System.Security.Cryptography.X509Certificates;
+using lib.Net;
 //using System.Threading.Tasks;
 
 static public class log
@@ -27,6 +28,9 @@ static public class log
 		Warn = 5,
 		Error = 6,
 		Fatal = 7,
+
+		Time = 64,
+		Raw = 65,
 	}
 
 	[Flags]
@@ -34,7 +38,7 @@ static public class log
 	{
 		None = 0,
 
-		File = 1 <<	0,
+		File = 1 << 0,
 		Console = 1 << 1,
 
 		All = File | Console,
@@ -62,6 +66,7 @@ static public class log
 		{
 
 			//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();
@@ -71,15 +76,14 @@ static public class log
 				}
 				else
 				{
-                    var pathPieces = path.Split( '\\' );
+					var pathPieces = path.Split( '\\' );
 
-					if(pathPieces.Length < 2)
+					if( pathPieces.Length < 2 )
 					{
-                        pathPieces = path.Split('/');
+						pathPieces = path.Split( '/' );
-                    }
+					}
 
-
+					var lastDir = pathPieces[pathPieces.Length - 2];
-                    var lastDir = pathPieces[ pathPieces.Length - 2 ];
 
 					ImmutableInterlocked.AddOrUpdate( ref s_shortname, pathHash, lastDir, ( key, value ) => { return lastDir; } );
 
@@ -97,38 +101,18 @@ static public class log
 			Obj = obj;
 		}
 	}
+	static LogEvent CreateLogEvent( LogType logType, string msg, string cat, object obj, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "" )
+	{
+		var logEvent = new LogEvent( logType, msg, path, line, member, cat, obj );
+
+		return logEvent;
+	}
+
+
 
 	public delegate void Log_delegate( LogEvent evt );
 
-	static ImmutableDictionary<int, string> s_files = ImmutableDictionary<int, string>.Empty;
 
-	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;
-	}
 
 
 
@@ -137,7 +121,6 @@ static public class log
 		startup( filename, endpoints );
 	}
 
-
 	static public void destroy()
 	{
 		string msg = "==============================================================================\nLogfile shutdown at " + DateTime.Now.ToString();
@@ -150,13 +133,6 @@ static public class log
 	}
 
 
-	static LogEvent CreateLogEvent( LogType logType, string msg, string cat, object obj, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "" )
-	{
-		var logEvent = new LogEvent( logType, msg, path, line, member, cat, obj );
-
-		return logEvent;
-	}
-
 	static internal ConcurrentQueue<LogEvent> s_events = new ConcurrentQueue<LogEvent>();
 
 	static private Thread s_thread;
@@ -173,10 +149,41 @@ static public class 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;
+		if( fullPath.Length < s_cwdLength )
+			return fullPath;
 
 		var rel = fullPath.Substring( s_cwdLength + 1 );
 
@@ -187,8 +194,9 @@ static public class log
 	{
 		return relativePath( path );
 	}
+#endregion // Util
 
-	// Forwards.
+#region Forwards
 	static public void fatal( string msg, string cat = "", object obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "" )
 	{
 		logBase( msg, LogType.Fatal, path, line, member, cat, obj );
@@ -204,9 +212,9 @@ static public class log
 		logBase( msg, LogType.Warn, path, line, member, cat, obj );
 	}
 
-	static public void high(string msg, string cat = "", object obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "")
+	static public void high( string msg, string cat = "", object obj = null, [CallerFilePath] string path = "", [CallerLineNumber] int line = -1, [CallerMemberName] string member = "" )
 	{
-		logBase(msg, LogType.High, path, line, member, cat, obj);
+		logBase( msg, LogType.High, path, line, member, cat, obj );
 	}
 
 	static public void info( string msg, string cat = "", object obj = null,
@@ -224,28 +232,10 @@ static public class log
 	{
 		logBase( msg, LogType.Trace, path, line, member, cat, obj );
 	}
-
+	#endregion
-	static object s_lock = new object();
-
-	static public void logBase_old( string msg, LogType type = LogType.Debug, string path = "", int line = -1, string member = "", string cat = "unk", object obj = null )
-	{
-		// @@@@@ TODO Get rid of this lock.
-		var evt = new LogEvent( type, msg, path, line, member, cat, obj );
-
-		lock( s_lock )
-		{
-			writeToAll( evt );
-		}
-	}
-
-	static public void logBase( string msg, LogType type = LogType.Debug, string path = "", int line = -1, string member = "", string cat = "unk", object obj = null )
-	{
-		var evt = new LogEvent( type, msg, path, line, member, cat, obj );
-
-		s_events.Enqueue( evt );
-	}
 
 
+#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 = "" )
 	{
 		var list = refl.GetAllProperties( obj.GetType() );
@@ -253,16 +243,10 @@ static public class log
 		lock( s_lock )
 		{
 			var evt = new LogEvent( type, header, path, line, member, cat, obj );
-			//var evt = CreateLogEvent( type, header, cat, obj );
-
-			//lock( s_log )
 			{
-				//var evt = CreateLogEvent( type, header, cat, obj );
 
 				s_events.Enqueue( evt );
 
-				//s_log.writeToAll( evt );
-
 				foreach( var pi in list )
 				{
 					try
@@ -284,22 +268,43 @@ static public class log
 	//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( !value.Equals( notExpectedValue ) )
 		{
-			log.info( $"Properly got {value}{trueString}" );
+			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", object obj = null )
+	{
+		LogEvent evt = new LogEvent( type, msg, path, line, member, cat, obj );
+		return evt;
+	}
+
+
+	static public void logBase( string msg, LogType type = LogType.Debug, string path = "", int line = -1, string member = "", string cat = "unk", object obj = null )
+	{
+		var evt = logCreateEvent( msg, type, path, line, member, cat );
+
+		s_events.Enqueue( evt );
+	}
+
 
 	static Endpoints s_endpoints = Endpoints.Console;
 	static int s_catWidth = 14;
+	static int s_timeWidth = 6;
 
 	static void startup( string filename, Endpoints endpoints )
 	{
+		s_startTime = DateTime.Now;
+
 		s_cwd = Directory.GetCurrentDirectory();
 		s_cwdLength = s_cwd.Length;
 
@@ -308,6 +313,7 @@ static public class log
 		var start = new ThreadStart( run );
 
 		s_thread = new Thread( start );
+		s_thread.Priority = ThreadPriority.BelowNormal;
 		s_thread.Name = $"Logging";
 		s_thread.Start();
 
@@ -387,22 +393,14 @@ static public class log
 	{
 		switch( type )
 		{
-			case LogType.Trace:
+			case LogType.Trace: return ' ';
-				return ' ';
+			case LogType.Debug: return ' ';
-			case LogType.Debug:
+			case LogType.Info:  return ' ';
-				return ' ';
+			case LogType.High:  return '+';
-			case LogType.Info:
+			case LogType.Warn:  return '+';
-				return ' ';
+			case LogType.Error: return '*';
-			case LogType.High:
+			case LogType.Fatal: return '*';
-				return '+';
+			     default:       return '?';
-			case LogType.Warn:
-				return '+';
-			case LogType.Error:
-				return '*';
-			case LogType.Fatal:
-				return '*';
-			default:
-				return '?';
 		}
 	}
 
@@ -433,16 +431,35 @@ static public class log
 				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_lastTime = DateTime.MinValue;
+	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 msgHeader( LogEvent evt )
 	{
+		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 msgHdr = string.Format( $"{{0,-{s_catWidth}}}{{1}}| ", truncatedCat, sym );
+		var time = span.Milliseconds; // humanTime( secondSpan );
+
+		var msgHdr = string.Format( $"{s_timeHeader}{{0,-{s_timeWidth}}} | {{1,-{s_catWidth}}}{{2}}| ", time, truncatedCat, sym );
 
 		return msgHdr;
 	}
@@ -456,44 +473,87 @@ static public class log
 		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
 		{
-			// _SHOULDNT_ need this since we lock at the top.
+			#region Time
-			//lock( this )
+			var span = evt.Time - s_startTime;
+
+			var curSeconds = (int)span.TotalSeconds;
+
+			if( curSeconds - s_lastDisplaySeconds > 10 )
 			{
+				s_lastDisplaySeconds = curSeconds;
 
-				var finalLine = msgFrom( evt );
+				var minuteEvt = new LogEvent( LogType.Raw, $"T I M E ==> {evt.Time.Hour.ToString("D2")}:{evt.Time.Minute.ToString("D2")}:{evt.Time.Second.ToString("D2")}.{evt.Time.Millisecond.ToString("D4")} | {evt.Time.ToShortDateString()}", "", 0, "", "lib.time", null );
+				minuteEvt.Time = evt.Time;
+				writeSpecialEvent( minuteEvt );
+			}
 
-				//Console.WriteLine( finalMsg );
+			if( evt.LogType != LogType.Raw )
-				//Console.Out.Write( finalMsg );
+			{
+				var curSecond = (int)span.TotalSeconds;
 
-				if( (s_endpoints & Endpoints.File) == Endpoints.File )
+				if( s_lastSecond == curSecond )
 				{
-					s_writer.WriteLine( finalLine );
+					s_timeHeader = " ";
 				}
-
+				else
-				if( (s_endpoints & Endpoints.Console) == Endpoints.Console )
 				{
-					setConsoleColor( evt );
+					s_timeHeader = "*";
-						Console.WriteLine( finalLine );
+					s_lastSecond = curSecond;
-					Console.ResetColor();
-				}
-
-
-				//Debug.WriteLine( finalLine );
-
-				s_writer.Flush();
-
-				foreach( Log_delegate cb in s_delegates )
-				{
-					cb( evt );
 				}
 			}
+
+			#endregion
+
+
+			#region Write
+			var finalLine = msgFrom( evt );
+
+			if( ( s_endpoints & Endpoints.File ) == Endpoints.File )
+			{
+				s_writer.WriteLine( finalLine );
+			}
+
+			if( ( s_endpoints & Endpoints.Console ) == Endpoints.Console )
+			{
+				setConsoleColor( evt );
+				Console.WriteLine( finalLine );
+				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" );
@@ -507,23 +567,23 @@ static public class log
 			Debug.WriteLine( "EXCEPTION DURING LOGGING" );
 			Debug.WriteLine( "EXCEPTION DURING LOGGING" );
 			Debug.WriteLine( $"Exception {ex}" );
+		#endregion
 		}
+
 	}
 
-	public static void WriteToConsole(LogEvent evt)
+	public static void WriteToConsole( LogEvent evt )
 	{
-		char sym = getSymbol(evt.LogType);
+		char sym = getSymbol( evt.LogType );
 
-		var truncatedCat = evt.Cat.Substring(0, Math.Min(8, evt.Cat.Length));
+		var truncatedCat = evt.Cat.Substring( 0, Math.Min( 8, evt.Cat.Length ) );
 
-		string finalLine = string.Format("{0,-8}{1}| {2}", truncatedCat, sym, evt.Msg);
+		string finalLine = string.Format( "{0,-8}{1}| {2}", truncatedCat, sym, evt.Msg );
 
-		Console.WriteLine(finalLine);
+		Console.WriteLine( finalLine );
 	}
 
 
-
-
 	private static Stream s_stream;
 	private static StreamWriter s_writer;
 
@@ -532,12 +592,4 @@ static public class log
 
 	private static ArrayList s_delegates = new ArrayList();
 
-
-
-
-
-
-
-
-
 }

res/Resource.cs

@@ -28,8 +28,6 @@ public class Ref : lib.I_Serialize
 
 	public string Filename =>path;
 
-
-
 	//For construction
 	public Ref()
 	{
@@ -115,7 +113,6 @@ public class Ref<T> : Ref where T : class
 		return newRef;
 	}
 
-
 	[NonSerialized]
 	protected T m_res;
 
@@ -259,12 +256,10 @@ public class Mgr
 		return new Ref<T>( filename );
 	}
 
-	//*
 	static public Ref lookup( string filename, Type t )
 	{
 		return new Ref( filename );
 	}
-	//*/
 
 	// @@@ TODO Pass information through here
 	static public T? load<T>( string filename ) where T : class
@@ -289,16 +284,10 @@ public class Mgr
 
 	static public T actualLoad<T>( string filename ) where T : class
 	{
-
 		lock(s_loading)
 		{
-
 			if( s_loading.TryGetValue( filename, out var evt ) )
 			{
-
-				//var waiting = evt.WaitOne();
-
-
 				if( ResCache<T>.s_cache.TryGetValue( filename, out var holder ) )
 				{
 					if( holder.weak.TryGetTarget( out var v ) )
@@ -311,9 +300,6 @@ public class Mgr
 				}
 			}
 
-			//var evtNew = new AutoResetEvent( false );
-
-			//if( ImmutableInterlocked.TryAdd( ref s_loading, filename, evtNew ) )
 			{
 				if( Resource.mgr.m_loaders.TryGetValue( typeof( T ), out var loaderGen ) )
 				{
@@ -329,14 +315,6 @@ public class Mgr
 
 					var alreadyAdded = !ImmutableInterlocked.TryAdd( ref ResCache<T>.s_cache, filename, holder );
 
-					//evtNew.Set();
-
-					//Done loading
-					//if( !ImmutableInterlocked.TryRemove( ref s_loading, filename, out var oldEvt ) )
-					{
-						//log.error( $"Error removing loading event for {filename}" );
-					}
-
 					if( alreadyAdded )
 					{
 						log.error( $"Key {filename} already existed, though it shouldnt." );
@@ -351,7 +329,6 @@ public class Mgr
 					return ResCache<T>.s_default;
 				}
 			}
-
 		}
 
 		return actualLoad<T>( filename );