From 08cf4d3aca7bedff0a47df8e6cf16d7012705d42 Mon Sep 17 00:00:00 2001 From: Marc Hernandez Date: Sun, 5 May 2024 20:18:46 -0700 Subject: [PATCH] Fixes and verbose logging --- res/Resource.cs | 467 ++++++++++++++++++++++++------------------- ser/XmlFormatter2.cs | 56 +++++- 2 files changed, 305 insertions(+), 218 deletions(-) diff --git a/res/Resource.cs b/res/Resource.cs index 4aef9a9..795b2ae 100644 --- a/res/Resource.cs +++ b/res/Resource.cs @@ -7,259 +7,309 @@ using System.Diagnostics; using System.Reflection; using System.Collections.Immutable; using System.Threading; +using System.IO; +using Microsoft.CodeAnalysis; -namespace res +namespace res; + + +using ImmDefLoad = ImmutableQueue<(string name, Ref)>; + +public interface Res_old { +} - using ImmDefLoad = ImmutableQueue<(string name, Ref)>; +[DebuggerDisplay("Path = {path}")] +public class Ref : lib.I_Serialize +{ + static public bool s_verboseLogging = true; - public interface Res_old + public string Filename =>path; + + //For construction + public Ref() + { + path = "{set_from_ref_default_cons}"; + if( s_verboseLogging ) log.info( $"Ref: {GetType().Name} {path}" ); + } + + public Ref( string filename ) + { + path = filename; + if( s_verboseLogging ) log.info( $"Ref: {GetType().Name} {path}" ); + } + + virtual public void OnChange() + { + } + + virtual internal void load() { } - [Serializable] - public class Ref : lib.I_Serialize + private string path = "{set_from_inline_cons}"; +} + +[Serializable] +[DebuggerDisplay("Path = {path} / Res = {res}")] +public class Ref : Ref where T : class +{ + public T? res => m_res != null ? m_res : lookup(); + + + public T? lookup() { - public string Filename =>path; - - //For construction - public Ref() - { - path = "{UNSET_CONS}"; - } - - public Ref( string filename ) - { - path = filename; - } - - virtual public void OnSerialize() - { - } - - virtual public void OnDeserialize( object enclosing ) - { - } - - virtual public void OnChange() - { - } - - virtual internal void load() - { - - } - - private string path = "{UNSET_INLINE}"; + m_res = Mgr.load( Filename ); + if( s_verboseLogging ) log.info( $"Ref.lookup {GetType().Name} {GetType().GenericTypeArguments[0]} path {Filename}" ); + return m_res; } - [Serializable] - public class Ref : Ref where T : class + //For serialization + public Ref() + : + base( "{set_from_ref<>_default_cons}" ) { - public T? res => m_res != null ? m_res : ( m_res = Mgr.load( Filename ) ); + if( s_verboseLogging ) log.info( $"Ref {GetType().Name} {GetType().GenericTypeArguments[0]} path {Filename}" ); + } - //For serialization - public Ref() - : - base( "{unknown}" ) + public Ref( string filename ) + : + base( filename ) + { + if( s_verboseLogging ) log.info( $"Ref {GetType().Name} {GetType().GenericTypeArguments[0]} path {Filename}" ); + } + + override internal void load() + { + m_res = Mgr.load( Filename ); + if( s_verboseLogging ) log.info( $"Ref.load {GetType().Name} {GetType().GenericTypeArguments[0]} path {Filename}" ); + } + + public object OnDeserialize( object enclosing ) + { + return enclosing; + } + + static public Ref createAsset( T v, string path ) + { + if( File.Exists( path ) ) { + log.warn( $"For {typeof(T).Name}, saving asset to {path}, but it already exists" ); + + var newPath = $"{path}_{DateTime.Now.ToShortDateString()}_{DateTime.Now.ToShortTimeString()}"; + + System.IO.File.Move(path, newPath ); + + log.warn( $"For {typeof(T).Name}, renamed to {newPath}" ); } - public Ref( string filename ) - : - base( filename ) - { - } - - /* - public Ref( string filename, T res ) : base( filename ) - { - m_res = res; - } - */ - - override internal void load() - { - m_res = Mgr.load( Filename ); - } - - - [NonSerialized] - private T m_res; + var newRef = new Ref( path ); + return newRef; } + [NonSerialized] + protected T m_res; +} - public class Resource +public class RefMemory : Ref where T : class +{ + + //For serialization + public RefMemory( T res ) + : + base( "{memory}" ) { - static public Mgr mgr; - + m_res = res; } - - /* - public class Loader + override internal void load() { - static public T load( string filename ) - { - Debug.Assert( false, "Specialize Loader for your type for file" ); - return default(T); - } - } - */ - - public delegate T Load( string filename ); - - - class LoadHolder - { - internal virtual object load() - { - return null; - } } +} - class LoadHolder : LoadHolder + + + +public class Resource +{ + static public Mgr mgr; + +} + + +public delegate T Load( string filename ); + + +class LoadHolder +{ + internal virtual object load() { - public LoadHolder( Load fnLoad ) - { - _fnLoad = fnLoad; - } + return null; + } +} - public Load _fnLoad; - internal override object load() - { - return load(); - } +class LoadHolder : LoadHolder +{ + public LoadHolder( Load fnLoad ) + { + _fnLoad = fnLoad; } - //generic classes make a new static per generic type - class ResCache where T : class + public Load _fnLoad; + + internal override object load() { - public static T s_default = default; - public static ImmutableDictionary> s_cache = ImmutableDictionary>.Empty; + return load(); + } +} + +public record class ResourceHolder( WeakReference weak, string Name, DateTime captured ) : imm.Recorded> +where T : class +{ + +} + +//generic classes make a new static per generic type +class ResCache where T : class +{ + public static T s_default = default; + public static ImmutableDictionary> s_cache = ImmutableDictionary>.Empty; +} + + +public class Mgr +{ + static public void startup() + { + Resource.mgr = new Mgr(); } - - public class Mgr + static public void register( Load loader ) { - static public void startup() + Debug.Assert( !Resource.mgr.m_loaders.ContainsKey( typeof( T ) ) ); + + var lh = new LoadHolder( loader ); + + ImmutableInterlocked.TryAdd( ref Resource.mgr.m_loaders, typeof( T ), lh ); + } + + //Register all subclasses of a particular type + //???? Should we just always do this? + static public void registerSub() + { + registerSub( typeof(T) ); + } + + static public void registerSub( Type baseType ) + { + log.info( $"Registering loader for {baseType.Name}" ); + + Type[] typeParams = new Type[1]; + foreach( var mi in baseType.GetMethods() ) { - Resource.mgr = new Mgr(); - } - - static public void register( Load loader ) - { - Debug.Assert( !Resource.mgr.m_loaders.ContainsKey( typeof( T ) ) ); - - var lh = new LoadHolder( loader ); - - ImmutableInterlocked.TryAdd( ref Resource.mgr.m_loaders, typeof( T ), lh ); - } - - //Register all subclasses of a particular type - //???? Should we just always do this? - static public void registerSub() - { - registerSub( typeof(T) ); - } - - static public void registerSub( Type baseType ) - { - log.info( $"Registering loader for {baseType.Name}" ); - - Type[] typeParams = new Type[1]; - foreach( var mi in baseType.GetMethods() ) + if( mi.Name == "res_load" && mi.IsGenericMethod ) { - if( mi.Name == "res_load" && mi.IsGenericMethod ) + foreach( var ass in AppDomain.CurrentDomain.GetAssemblies() ) { - foreach( var ass in AppDomain.CurrentDomain.GetAssemblies() ) + foreach( var t in ass.GetTypes() ) { - foreach( var t in ass.GetTypes() ) - { - if( !baseType.IsAssignableFrom( t ) ) - continue; + if( !baseType.IsAssignableFrom( t ) ) + continue; - log.debug( $"Making a loader for {t.Name}" ); + log.debug( $"Making a loader for {t.Name}" ); - typeParams[0] = t; - var mi_ng = mi.MakeGenericMethod( typeParams ); + typeParams[0] = t; + var mi_ng = mi.MakeGenericMethod( typeParams ); - var loadGenType = typeof( Load<> ); + var loadGenType = typeof( Load<> ); - var loadType = loadGenType.MakeGenericType( t ); + var loadType = loadGenType.MakeGenericType( t ); - var loader = Delegate.CreateDelegate( loadType, mi_ng ); + var loader = Delegate.CreateDelegate( loadType, mi_ng ); - var lhGenType = typeof( LoadHolder<> ); + var lhGenType = typeof( LoadHolder<> ); - var lhType = lhGenType.MakeGenericType( t ); + var lhType = lhGenType.MakeGenericType( t ); - var lh = Activator.CreateInstance( lhType, loader ) as LoadHolder; + var lh = Activator.CreateInstance( lhType, loader ) as LoadHolder; - ImmutableInterlocked.TryAdd( ref Resource.mgr.m_loaders, t, lh ); - } + ImmutableInterlocked.TryAdd( ref Resource.mgr.m_loaders, t, lh ); } - return; } + return; } } + } - static public Ref lookup( string filename ) where T : class + static public Ref lookup( string filename ) where T : class + { + return new Ref( filename ); + } + + //* + static public Ref lookup( string filename, Type t ) + { + return new Ref( filename ); + } + //*/ + + // @@@ TODO Pass information through here + static public T? load( string filename ) where T : class + { + if( ResCache.s_cache.TryGetValue( filename, out var holder ) ) { - return new Ref( filename ); - } - //* - static public Ref lookup( string filename, Type t ) - { - return new Ref( filename ); - } - //*/ - - static public T? load( string filename ) where T : class - { - if( ResCache.s_cache.TryGetValue( filename, out var wr ) ) + if( holder.weak.TryGetTarget( out var v ) ) { - if( wr.TryGetTarget( out var v ) ) - return v; - - log.info( $"{filename} was in cache, but its been dropped, reloading." ); + return v; } - log.warn( $"Block Loading {filename}." ); - - var newV = actualLoad( filename ); - - return newV; + log.info( $"{filename} was in cache, but its been dropped, reloading." ); } - static public T actualLoad( string filename ) where T : class + log.warn( $"Block Loading {filename}." ); + + var newV = actualLoad( filename ); + + return newV; + } + + static public T actualLoad( string filename ) where T : class + { + + lock(s_loading) { + if( s_loading.TryGetValue( filename, out var evt ) ) { - evt.WaitOne(); - if( ResCache.s_cache.TryGetValue( filename, out var wr ) ) + //var waiting = evt.WaitOne(); + + + if( ResCache.s_cache.TryGetValue( filename, out var holder ) ) { - if( wr.TryGetTarget( out var v ) ) + if( holder.weak.TryGetTarget( out var v ) ) + { + log.trace( $"{typeof(T).Name} loading {filename}" ); return v; + } log.error( $"{filename} was in cache, but its been dropped, reloading." ); } } - var evtNew = new AutoResetEvent( false ); + //var evtNew = new AutoResetEvent( false ); - if( ImmutableInterlocked.TryAdd( ref s_loading, filename, evtNew ) ) + //if( ImmutableInterlocked.TryAdd( ref s_loading, filename, evtNew ) ) { if( Resource.mgr.m_loaders.TryGetValue( typeof( T ), out var loaderGen ) ) { @@ -269,14 +319,18 @@ namespace res var weak = new WeakReference( v ); - var alreadyAdded = !ImmutableInterlocked.TryAdd( ref ResCache.s_cache, filename, weak ); + var holder = new ResourceHolder( weak, $"", DateTime.Now ).Record(); - evtNew.Set(); + log.info( $"To {typeof(T).Name} add {filename}" ); + + var alreadyAdded = !ImmutableInterlocked.TryAdd( ref ResCache.s_cache, filename, holder ); + + //evtNew.Set(); //Done loading - if( !ImmutableInterlocked.TryRemove( ref s_loading, filename, out var oldEvt ) ) + //if( !ImmutableInterlocked.TryRemove( ref s_loading, filename, out var oldEvt ) ) { - log.error( $"Error removing loading event for {filename}" ); + //log.error( $"Error removing loading event for {filename}" ); } if( alreadyAdded ) @@ -294,49 +348,46 @@ namespace res } } - return actualLoad( filename ); } - static object s_loadingLock = new object(); + return actualLoad( filename ); + } - static ImmutableDictionary s_loading = ImmutableDictionary.Empty; - static ImmDefLoad s_deferredLoad = ImmDefLoad.Empty; + static object s_loadingLock = new object(); + + static ImmutableDictionary s_loading = ImmutableDictionary.Empty; + static ImmDefLoad s_deferredLoad = ImmDefLoad.Empty; - Mgr() + Mgr() + { + log.info( $"Creating Res.Mgr" ); + + var ts = new ThreadStart( deferredLoader ); + + m_deferredLoader = new Thread( ts ); + + m_deferredLoader.Start(); + } + + void deferredLoader() + { + while( true ) { - log.info( $"Creating Res.Mgr" ); + Thread.Sleep( 1 ); - var ts = new ThreadStart( deferredLoader ); - - m_deferredLoader = new Thread( ts ); - - m_deferredLoader.Start(); - } - - void deferredLoader() - { - while( true ) + if( ImmutableInterlocked.TryDequeue( ref s_deferredLoad, out var v ) ) { - Thread.Sleep( 1 ); - - if( ImmutableInterlocked.TryDequeue( ref s_deferredLoad, out var v ) ) - { - v.Item2.load(); - } + v.Item2.load(); } } - - - - ImmutableDictionary m_loaders = ImmutableDictionary.Empty; - - Thread m_deferredLoader; - } + ImmutableDictionary m_loaders = ImmutableDictionary.Empty; + Thread m_deferredLoader; } + diff --git a/ser/XmlFormatter2.cs b/ser/XmlFormatter2.cs index f92fddc..d17b0fb 100644 --- a/ser/XmlFormatter2.cs +++ b/ser/XmlFormatter2.cs @@ -38,8 +38,8 @@ namespace lib public interface I_Serialize { - void OnSerialize(); - void OnDeserialize( object enclosing ); + void OnSerialize() {} + object OnDeserialize( object enclosing ) => this; } [Flags] @@ -123,6 +123,8 @@ namespace lib public class XmlFormatter2Cfg : Config { + public bool VerboseLogging = true; + public Datastructure datastructure = Datastructure.Tree; public int Version = 2; @@ -286,6 +288,8 @@ namespace lib { TypeCode typeCode = Type.GetTypeCode( type ); + if( _cfg.VerboseLogging ) log.info( $"{type.Name}.{name} {existing} {mi?.Name}" ); + if( typeCode != TypeCode.Object ) { return DeserializeConcrete( elem, mi, name, type ); @@ -302,11 +306,10 @@ namespace lib { object obj = DeserializeObject( elem, mi, type, existing ); - if( obj is I_Serialize ) + if( obj is I_Serialize iser ) { - var iser = obj as I_Serialize; - - iser.OnDeserialize( null ); + if( _cfg.VerboseLogging ) log.info( $"" ); + obj = iser.OnDeserialize( null ); } return obj; @@ -320,7 +323,7 @@ namespace lib } catch( Exception ex ) { - log.warn( $"Caught exception fn {mi.Name} type {type.Name} of {ex.Message}" ); + log.warn( $"Caught exception fn {mi?.Name} type {type?.Name} of {ex.Message}" ); } return existing; @@ -343,6 +346,8 @@ namespace lib private object DeserializeConcrete( XmlElement elem, MemberInfo mi, string name, Type type ) { + if( _cfg.VerboseLogging ) log.info( $"" ); + string val = ""; if( elem.HasAttribute( "v" ) ) @@ -425,6 +430,8 @@ namespace lib private object HydrateObject( XmlElement elem, MemberInfo mi, Type finalType, object obj ) { + if( _cfg.VerboseLogging ) log.info( $"" ); + if( obj is IList ) { var list = obj as IList; @@ -513,6 +520,8 @@ namespace lib private object HydrateObjectOfNarrowType( XmlElement elem, MemberInfo mi, Type narrowType, object obj ) { + if( _cfg.VerboseLogging ) log.info( $"" ); + var isImm = typeof(imm.Imm).IsAssignableFrom( narrowType ); XmlNodeList allChildren = elem.ChildNodes; @@ -671,6 +680,7 @@ namespace lib private object GetObjectForDeser( XmlElement elem, Type type, out Type finalType, object obj ) { + finalType = type; if( elem.HasAttribute( "_.t" ) ) { @@ -685,6 +695,8 @@ namespace lib int refInt = refString.Length > 0 ? Convert.ToInt32( refString ) : -1; + if( _cfg.VerboseLogging ) log.info( $"{finalType?.Name}({type?.Name}) refInt {refInt} exitingObj = {obj?.ToString()}" ); + obj = createObject( elem, finalType, refInt, obj ); return obj; @@ -692,6 +704,8 @@ namespace lib private object DeserializeList( XmlElement elem, MemberInfo mi, Type type, IList list ) { + if( _cfg.VerboseLogging ) log.info( $"" ); + XmlNodeList arrNodeList = elem.ChildNodes; Type t = list.GetType(); @@ -726,6 +740,7 @@ namespace lib typeElem = typeof( KeyValuePair<,> ).MakeGenericType( type.GenericTypeArguments ); } + if( _cfg.VerboseLogging ) log.info( $"DserCol {type.GetType().Name} {typeElem.Name} into reflT {mi.ReflectedType.Name} declT {mi.DeclaringType.Name} {mi.Name}" ); string refString = elem.GetAttribute( "ref" ); int refInt = refString.Length > 0 ? Convert.ToInt32( refString ) : -1; @@ -752,7 +767,9 @@ namespace lib finalType = typeElem; } - arr.SetValue( Deserialize( arrElem, mi, finalType, null ), i ); + var arrItem = Deserialize( arrElem, mi, finalType, null ); + + arr.SetValue( arrItem, i ); } } @@ -768,6 +785,8 @@ namespace lib var typeGen = Type.MakeGenericSignatureType( type ); + if( _cfg.VerboseLogging ) log.info( $"TypeGen: {typeGen.Name}" ); + if( type == typeof( ImmutableArray<> ).MakeGenericType( typeElem ) ) { var genMeth = GetType().GetMethod( "MakeImmutableArray", BindingFlags.Instance | BindingFlags.Public | BindingFlags.NonPublic ); @@ -823,6 +842,8 @@ namespace lib private object DeserializeArray( XmlElement elem, MemberInfo mi, Type type ) { + if( _cfg.VerboseLogging ) log.info( $"" ); + Type typeElem = type.GetElementType(); string refString = elem.GetAttribute( "ref" ); @@ -866,11 +887,12 @@ namespace lib private object createObject( XmlElement elem, Type type, int refInt, object existingObj ) { + TypeCode tc = Type.GetTypeCode( type ); if( _cfg.datastructure == Datastructure.Graph && refInt > 0 && m_alreadySerialized.ContainsKey( refInt ) ) { - //lib.log.info( "Reusing object for {0}", refInt ); + if( _cfg.VerboseLogging ) log.info( $"Reuse object" ); return m_alreadySerialized[refInt]; } @@ -880,6 +902,7 @@ namespace lib if( isProxy ) { + if( _cfg.VerboseLogging ) log.info( $"use Proxy" ); object obj = null; var tryType = type; @@ -921,28 +944,41 @@ namespace lib var isSubclass = type.IsSubclassOf( existingObjType ) || existingObjType.IsSubclassOf( type ); if( isSubclass ) + { + if( _cfg.VerboseLogging ) log.info( $"Using existing obj {existingObj?.ToString()}" ); return existingObj; + } // old //if( type == existingObjType ) return existingObj; } + if( typeof(res.Ref).IsAssignableFrom( type ) ) + { + log.info( $"Ref time!" ); + } + // THIRD create a new object { object obj = null; try { + if( _cfg.VerboseLogging ) log.info( $"Activator.CreateInstance" ); + //Trying the nice way to creat objects first. obj = Activator.CreateInstance( type ); + if( _cfg.VerboseLogging ) log.info( $"Got obj {obj?.ToString()}" ); } - catch( Exception ) + catch( Exception ex ) { try { + if( _cfg.VerboseLogging ) log.info( $"GetUninitializedObject" ); obj = System.Runtime.Serialization.FormatterServices.GetUninitializedObject( type ); + if( _cfg.VerboseLogging ) log.info( $"Got obj {obj?.ToString()}" ); } catch( Exception exInner ) {