fermyon / spin-dotnet-sdk

Apache License 2.0
43 stars 11 forks source link

Question on (error) logging #39

Open christophwille opened 2 years ago

christophwille commented 2 years ago

I have a catch clause:

        catch (Exception ex)
        {
            // TODO: how to log this properly? (Console?)
            exception = ex.ToString();
        }

https://github.com/christophwille/SpinHello/blob/27ee9a28351866fd167ed10039829ba6b8e704eb/src/Handler/Handler.cs#L84

I remember the comparison to CGI with error console out; does this apply/work in .NET that way too?

radu-matei commented 2 years ago

Console.WriteLine works — Spin captures both standard output and standard error and sends them to log files in ~/.spin/<application-name>/logs/.

You can also run spin up --follow-all to get the logs directly.

christophwille commented 2 years ago

Ok, so basically one more thing to properly wrap to be to unit test "Did it log error conditions properly?" Maybe I can reuse ConsoleLogger/ILogger.

christophwille commented 2 years ago

My idea with doing a standard ILogger didn't fly, I am documenting it here if someone else has the same idea:

        var loggerFactory = LoggerFactory.Create(builder =>
        {
            builder.AddFilter("spin", LogLevel.Debug)
                   .AddConsole();
        });

        Logger = loggerFactory.CreateLogger("spin");
  Unhandled Exception:
  System.TypeInitializationException: The type initializer for 'SpinHello.Handler' threw an exception.
   ---> System.PlatformNotSupportedException: Operation is not supported on this platform.
     at System.Threading.Thread.ThrowIfNoThreadStart()
     at System.Threading.Thread.Start(Boolean captureContext)
     at System.Threading.Thread.Start()
     at Microsoft.Extensions.Logging.Console.ConsoleLoggerProcessor..ctor()
     at Microsoft.Extensions.Logging.Console.ConsoleLoggerProvider..ctor(IOptionsMonitor`1 options, IEnumerable`1 formatters)
     at System.Reflection.RuntimeConstructorInfo.InvokeNonEmitUnsafe(Object obj, IntPtr* byrefParameters, Span`1 argsForTemporaryMonoSupport, BindingFlags invokeAttr)
     at System.Reflection.ConstructorInvoker.InvokeUnsafe(Object obj, IntPtr* args, Span`1 argsForTemporaryMonoSupport, BindingFlags invokeAttr)
     at System.Reflection.RuntimeConstructorInfo.Invoke(BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2[[Microsoft.Extensions.DependencyInjection.ServiceLookup.RuntimeResolverContext, Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60],[System.Object, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].VisitCallSiteMain(ServiceCallSite callSite, RuntimeResolverContext argument)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2[[Microsoft.Extensions.DependencyInjection.ServiceLookup.RuntimeResolverContext, Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60],[System.Object, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].VisitCallSite(ServiceCallSite callSite, RuntimeResolverContext argument)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitIEnumerable(IEnumerableCallSite enumerableCallSite, RuntimeResolverContext context)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2[[Microsoft.Extensions.DependencyInjection.ServiceLookup.RuntimeResolverContext, Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60],[System.Object, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].VisitCallSiteMain(ServiceCallSite callSite, RuntimeResolverContext argument)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2[[Microsoft.Extensions.DependencyInjection.ServiceLookup.RuntimeResolverContext, Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60],[System.Object, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].VisitCallSite(ServiceCallSite callSite, RuntimeResolverContext argument)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2[[Microsoft.Extensions.DependencyInjection.ServiceLookup.RuntimeResolverContext, Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60],[System.Object, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].VisitCallSiteMain(ServiceCallSite callSite, RuntimeResolverContext argument)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2[[Microsoft.Extensions.DependencyInjection.ServiceLookup.RuntimeResolverContext, Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60],[System.Object, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].VisitCallSite(ServiceCallSite callSite, RuntimeResolverContext argument)
     at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)
     at Microsoft.Extensions.DependencyInjection.ServiceProvider.CreateServiceAccessor(Type serviceType)
     at System.Collections.Concurrent.ConcurrentDictionary`2[[System.Type, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Func`2[[Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngineScope, Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60],[System.Object, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].GetOrAdd(Type key, Func`2 valueFactory)
     at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope)
     at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType)
     at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetService[ILoggerFactory](IServiceProvider provider)
     at Microsoft.Extensions.Logging.LoggerFactory.Create(Action`1 configure)
     at SpinHello.Handler..cctor()
     --- End of inner exception stack trace ---
christophwille commented 2 years ago

I added logging like this https://github.com/christophwille/SpinHello/blob/abef0de9810abe2894f1906e5dd740e672f19b34/src/Handler/Handler.cs#L98 (implemented via https://github.com/christophwille/SpinHello/blob/abef0de9810abe2894f1906e5dd740e672f19b34/src/Handler/SpinLogger.cs). That also allows me to mock the thing.

itowlson commented 2 years ago

Thanks for working through this and taking the time to document your solutions - really appreciate it!