Switch to ILogger-based logging

src/MagicOnion.Server.Redis/RedisGroup.cs

@@ -5,20 +5,22 @@
 using MessagePack;
 using StackExchange.Redis;
 using System.Collections.Concurrent;
+using Microsoft.Extensions.Logging;
 
 namespace MagicOnion.Server.Redis;
 
 public class RedisGroupRepository : IGroupRepository
 {
-    IMagicOnionSerializer messageSerializer;
-    IMagicOnionLogger logger;
+    readonly IMagicOnionSerializer messageSerializer;
+    readonly ILogger logger;
+
     ConnectionMultiplexer connection;
     int db;
 
     readonly Func<string, IGroup> factory;
     ConcurrentDictionary<string, IGroup> dictionary = new ConcurrentDictionary<string, IGroup>();
 
-    public RedisGroupRepository(IMagicOnionSerializer messageSerializer, RedisGroupOptions redisGroupOptions, IMagicOnionLogger logger)
+    public RedisGroupRepository(IMagicOnionSerializer messageSerializer, RedisGroupOptions redisGroupOptions, ILogger logger)
     {
         this.messageSerializer = messageSerializer;
         this.logger = logger;

src/MagicOnion.Server.Redis/RedisGroupRepositoryFactory.cs

@@ -2,20 +2,23 @@
 using MagicOnion.Server.Diagnostics;
 using MagicOnion.Server.Hubs;
 using MessagePack;
+using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
 
 namespace MagicOnion.Server.Redis;
 
 public class RedisGroupRepositoryFactory : IGroupRepositoryFactory
 {
-    private readonly RedisGroupOptions options;
+    readonly RedisGroupOptions options;
+    readonly ILogger logger;
 
-    public RedisGroupRepositoryFactory(IOptionsMonitor<RedisGroupOptions> options)
+    public RedisGroupRepositoryFactory(IOptionsMonitor<RedisGroupOptions> options, ILogger<RedisGroup> logger)
     {
         this.options = options.CurrentValue;
+        this.logger = logger;
     }
 
-    public IGroupRepository CreateRepository(IMagicOnionSerializer messageSerializer, IMagicOnionLogger logger)
+    public IGroupRepository CreateRepository(IMagicOnionSerializer messageSerializer)
     {
         return new RedisGroupRepository(messageSerializer, options, logger);
     }

src/MagicOnion.Server/Diagnostics/MagicOnionServerLog.cs

@@ -0,0 +1,75 @@
+using Grpc.Core;
+using MagicOnion.Server.Hubs;
+using Microsoft.Extensions.Logging;
+
+namespace MagicOnion.Server.Diagnostics;
+
+public static partial class MagicOnionServerLog
+{
+    public static void BeginInvokeMethod(ILogger logger, ServiceContext context, Type type)
+        => BeginInvokeMethod(logger, MethodTypeToString(context.MethodType), context.CallContext.Method);
+
+    public static void EndInvokeMethod(ILogger logger, ServiceContext context, Type type, double elapsed, bool isErrorOrInterrupted)
+        => EndInvokeMethod(logger, MethodTypeToString(context.MethodType), context.CallContext.Method, elapsed, (isErrorOrInterrupted ? "error" : ""));
+
+    public static void WriteToStream(ILogger logger, ServiceContext context, Type type)
+        => WriteToStream(logger, MethodTypeToString(context.MethodType), context.CallContext.Method);
+
+    public static void ReadFromStream(ILogger logger, ServiceContext context, Type type, bool complete)
+        => ReadFromStream(logger, MethodTypeToString(context.MethodType), context.CallContext.Method, complete);
+
+    public static void BeginInvokeHubMethod(ILogger logger, StreamingHubContext context, ReadOnlyMemory<byte> request, Type type)
+        => BeginInvokeHubMethod(logger, context.Path, request.Length);
+
+    public static void EndInvokeHubMethod(ILogger logger, StreamingHubContext context, int responseSize, Type? type, double elapsed, bool isErrorOrInterrupted)
+        => EndInvokeHubMethod(logger, context.Path, responseSize, elapsed, isErrorOrInterrupted ? "error" : "");
+
+    public static void Error(ILogger logger, Exception ex, ServerCallContext context)
+        => ErrorOnServiceMethod(logger, ex, context.Method);
+    public static void Error(ILogger logger, Exception ex, StreamingHubContext context)
+        => ErrorOnHubMethod(logger, ex, context.Path);
+
+    // enum.ToString is slow.
+    static string MethodTypeToString(MethodType type) =>
+        type switch
+        {
+            MethodType.Unary => "Unary",
+            MethodType.ClientStreaming => "ClientStreaming",
+            MethodType.ServerStreaming => "ServerStreaming",
+            MethodType.DuplexStreaming => "DuplexStreaming",
+            _ => ((int)type).ToString(),
+        };
+
+    [LoggerMessage(EventId = 1, Level = LogLevel.Debug, EventName = nameof(BeginBuildServiceDefinition), Message = nameof(BeginBuildServiceDefinition))]
+    public static partial void BeginBuildServiceDefinition(ILogger logger);
+
+    [LoggerMessage(EventId = 2, Level = LogLevel.Debug, EventName = nameof(EndBuildServiceDefinition), Message = nameof(EndBuildServiceDefinition) +" elapsed:{elapsed}")]
+    public static partial void EndBuildServiceDefinition(ILogger logger, double elapsed);
+
+    [LoggerMessage(EventId = 3, Level = LogLevel.Debug, EventName = nameof(BeginInvokeMethod), Message = nameof(BeginInvokeMethod) + " type:{methodType} method:{method}")]
+    public static partial void BeginInvokeMethod(ILogger logger, string methodType, string method);
+
+    [LoggerMessage(EventId = 4, Level = LogLevel.Debug, EventName = nameof(EndInvokeMethod), Message = nameof(EndInvokeMethod) + " type:{methodType} method:{method} elapsed:{elapsed} {message}")]
+    public static partial void EndInvokeMethod(ILogger logger, string methodType, string method, double elapsed, string message);
+
+    [LoggerMessage(EventId = 5, Level = LogLevel.Debug, EventName = nameof(WriteToStream), Message = nameof(WriteToStream) + " type:{methodType} method:{method}")]
+    public static partial void WriteToStream(ILogger logger, string methodType, string method);
+
+    [LoggerMessage(EventId = 6, Level = LogLevel.Debug, EventName = nameof(ReadFromStream), Message = nameof(ReadFromStream) + " type:{methodType} method:{method} complete:{complete}")]
+    public static partial void ReadFromStream(ILogger logger, string methodType, string method, bool complete);
+
+    [LoggerMessage(EventId = 7, Level = LogLevel.Debug, EventName = nameof(BeginInvokeHubMethod), Message = nameof(BeginInvokeHubMethod) + " method:{method} size:{size}")]
+    public static partial void BeginInvokeHubMethod(ILogger logger, string method, int size);
+
+    [LoggerMessage(EventId = 8, Level = LogLevel.Debug, EventName = nameof(EndInvokeHubMethod), Message = nameof(EndInvokeHubMethod) + " method:{method} size:{size} elapsed:{elapsed} {message}")]
+    public static partial void EndInvokeHubMethod(ILogger logger, string method, int size, double elapsed, string message);
+
+    [LoggerMessage(EventId = 9, Level = LogLevel.Debug, EventName = nameof(InvokeHubBroadcast), Message = nameof(InvokeHubBroadcast) + " groupName:{groupName} size:{size} broadcastGroupCount:{broadcastGroupCount}")]
+    public static partial void InvokeHubBroadcast(ILogger logger, string groupName, int size, int broadcastGroupCount);
+
+    [LoggerMessage(EventId = 90, Level = LogLevel.Error, EventName = nameof(ErrorOnServiceMethod), Message = "A service handler throws an exception occurred in {method}")]
+    public static partial void ErrorOnServiceMethod(ILogger logger, Exception ex, string method);
+
+    [LoggerMessage(EventId = 91, Level = LogLevel.Error, EventName = nameof(ErrorOnHubMethod), Message = "A hub method handler throws an exception occurred in {path}")]
+    public static partial void ErrorOnHubMethod(ILogger logger, Exception ex, string path);
+}

src/MagicOnion.Server/Extensions/MagicOnionServicesExtensions.cs

@@ -1,36 +1,35 @@
-using System;
 using System.Reflection;
 using Grpc.AspNetCore.Server.Model;
 using MagicOnion.Server;
-using MagicOnion.Server.Diagnostics;
 using MagicOnion.Server.Glue;
 using MagicOnion.Server.Hubs;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.DependencyInjection.Extensions;
 using Microsoft.Extensions.Options;
 
+// ReSharper disable once CheckNamespace
 namespace Microsoft.Extensions.DependencyInjection;
 
 public static class MagicOnionServicesExtensions
 {
     public static IMagicOnionServerBuilder AddMagicOnion(this IServiceCollection services, Action<MagicOnionOptions>? configureOptions = null)
     {
         var configName = Options.Options.DefaultName;
-        services.AddSingleton<MagicOnionServiceDefinition>(sp => MagicOnionEngine.BuildServerServiceDefinition(sp, sp.GetRequiredService<IOptionsMonitor<MagicOnionOptions>>().Get(configName), sp.GetRequiredService<IMagicOnionLogger>()));
+        services.AddSingleton<MagicOnionServiceDefinition>(sp => MagicOnionEngine.BuildServerServiceDefinition(sp, sp.GetRequiredService<IOptionsMonitor<MagicOnionOptions>>().Get(configName)));
         return services.AddMagicOnionCore(configureOptions);
     }
 
     public static IMagicOnionServerBuilder AddMagicOnion(this IServiceCollection services, Assembly[] searchAssemblies, Action<MagicOnionOptions>? configureOptions = null)
     {
         var configName = Options.Options.DefaultName;
-        services.AddSingleton<MagicOnionServiceDefinition>(sp => MagicOnionEngine.BuildServerServiceDefinition(sp, searchAssemblies, sp.GetRequiredService<IOptionsMonitor<MagicOnionOptions>>().Get(configName), sp.GetRequiredService<IMagicOnionLogger>()));
+        services.AddSingleton<MagicOnionServiceDefinition>(sp => MagicOnionEngine.BuildServerServiceDefinition(sp, searchAssemblies, sp.GetRequiredService<IOptionsMonitor<MagicOnionOptions>>().Get(configName)));
         return services.AddMagicOnionCore(configureOptions);
     }
 
     public static IMagicOnionServerBuilder AddMagicOnion(this IServiceCollection services, IEnumerable<Type> searchTypes, Action<MagicOnionOptions>? configureOptions = null)
     {
         var configName = Options.Options.DefaultName;
-        services.AddSingleton<MagicOnionServiceDefinition>(sp => MagicOnionEngine.BuildServerServiceDefinition(sp, searchTypes, sp.GetRequiredService<IOptionsMonitor<MagicOnionOptions>>().Get(configName), sp.GetRequiredService<IMagicOnionLogger>()));
+        services.AddSingleton<MagicOnionServiceDefinition>(sp => MagicOnionEngine.BuildServerServiceDefinition(sp, searchTypes, sp.GetRequiredService<IOptionsMonitor<MagicOnionOptions>>().Get(configName)));
         return services.AddMagicOnionCore(configureOptions);
     }
 
@@ -39,7 +38,6 @@ static IMagicOnionServerBuilder AddMagicOnionCore(this IServiceCollection servic
         var configName = Options.Options.DefaultName;
         var glueServiceType = MagicOnionGlueService.CreateType();
 
-        services.TryAddSingleton<IMagicOnionLogger, NullMagicOnionLogger>();
         services.TryAddSingleton<IGroupRepositoryFactory, ImmutableArrayGroupRepositoryFactory>();
 
         services.AddSingleton<MagicOnionServiceDefinitionGlueDescriptor>(sp => new MagicOnionServiceDefinitionGlueDescriptor(glueServiceType, sp.GetRequiredService<MagicOnionServiceDefinition>()));