Logging refactoring

src/NHibernate.Example.Web/Infrastructure/AppSessionFactory.cs

@@ -13,7 +13,7 @@ public class AppSessionFactory
 
 		public AppSessionFactory(Microsoft.Extensions.Logging.ILoggerFactory loggerFactory)
 		{
-			NHibernate.LoggerProvider.SetLoggersFactory(new NHibernateToMicrosoftLoggerFactory(loggerFactory));
+			NHibernate.NHibernateLogger.SetLoggersFactory(new NHibernateToMicrosoftLoggerFactory(loggerFactory));
 
 			var mapper = new ModelMapper();
 			mapper.AddMapping<ItemMap>();

src/NHibernate.Example.Web/Infrastructure/NHibernateToMicrosoftLogger.cs

@@ -1,9 +1,11 @@
 using System;
+using System.Collections.Generic;
 using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Internal;
 
 namespace NHibernate.Example.Web.Infrastructure
 {
-	public class NHibernateToMicrosoftLogger : IInternalLogger
+	public class NHibernateToMicrosoftLogger : INHibernateLogger
 	{
 		private readonly ILogger _msLogger;
 
@@ -12,122 +14,29 @@ public NHibernateToMicrosoftLogger(ILogger msLogger)
 			_msLogger = msLogger ?? throw new ArgumentNullException(nameof(msLogger));
 		}
 
-		public void Error(object message)
+		private static readonly Dictionary<NHibernateLogLevel, LogLevel> MapLevels = new Dictionary<NHibernateLogLevel, LogLevel>
 		{
-			if (IsErrorEnabled)
-			{
-				_msLogger.LogError(message.ToString());
-			}
-		}
-
-		public void Error(object message, Exception exception)
-		{
-			if (IsErrorEnabled)
-			{
-				_msLogger.LogError(exception, message.ToString());
-			}
-		}
-
-		public void ErrorFormat(string format, params object[] args)
-		{
-			if (IsErrorEnabled)
-			{
-				_msLogger.LogError(format, args);
-			}
-		}
-
-		public void Fatal(object message)
-		{
-			if (IsFatalEnabled)
-			{
-				_msLogger.LogCritical(message.ToString());
-			}
-		}
-
-		public void Fatal(object message, Exception exception)
-		{
-			if (IsFatalEnabled)
-			{
-				_msLogger.LogCritical(exception, message.ToString());
-			}
-		}
-
-		public void Debug(object message)
-		{
-			if (IsDebugEnabled)
-			{
-				_msLogger.LogDebug(message.ToString());
-			}
-		}
+			{ NHibernateLogLevel.Trace, LogLevel.Trace },
+			{ NHibernateLogLevel.Debug, LogLevel.Debug },
+			{ NHibernateLogLevel.Warn, LogLevel.Warning },
+			{ NHibernateLogLevel.Error, LogLevel.Error },
+			{ NHibernateLogLevel.Fatal, LogLevel.Critical },
+			{ NHibernateLogLevel.None, LogLevel.None },
+		};
 
-		public void Debug(object message, Exception exception)
+		public void Log(NHibernateLogLevel logLevel, NHibernateLogValues state, Exception exception)
 		{
-			if (IsDebugEnabled)
-			{
-				_msLogger.LogDebug(exception, message.ToString());
-			}
+			_msLogger.Log(MapLevels[logLevel], 0, new FormattedLogValues(state.Format, state.Args), exception, MessageFormatter);
 		}
 
-		public void DebugFormat(string format, params object[] args)
+		public bool IsEnabled(NHibernateLogLevel logLevel)
 		{
-			if (IsDebugEnabled)
-			{
-				_msLogger.LogDebug(format, args);
-			}
+			return _msLogger.IsEnabled(MapLevels[logLevel]);
 		}
 
-		public void Info(object message)
+		private static string MessageFormatter(object state, Exception error)
 		{
-			if (IsInfoEnabled)
-			{
-				_msLogger.LogInformation(message.ToString());
-			}
+			return state.ToString();
 		}
-
-		public void Info(object message, Exception exception)
-		{
-			if (IsInfoEnabled)
-			{
-				_msLogger.LogInformation(exception, message.ToString());
-			}
-		}
-
-		public void InfoFormat(string format, params object[] args)
-		{
-			if (IsInfoEnabled)
-			{
-				_msLogger.LogInformation(format, args);
-			}
-		}
-
-		public void Warn(object message)
-		{
-			if (IsWarnEnabled)
-			{
-				_msLogger.LogWarning(message.ToString());
-			}
-		}
-
-		public void Warn(object message, Exception exception)
-		{
-			if (IsWarnEnabled)
-			{
-				_msLogger.LogWarning(exception, message.ToString());
-			}
-		}
-
-		public void WarnFormat(string format, params object[] args)
-		{
-			if (IsWarnEnabled)
-			{
-				_msLogger.LogWarning(format, args);
-			}
-		}
-
-		public bool IsErrorEnabled => _msLogger.IsEnabled(LogLevel.Error);
-		public bool IsFatalEnabled => _msLogger.IsEnabled(LogLevel.Critical);
-		public bool IsDebugEnabled => _msLogger.IsEnabled(LogLevel.Debug);
-		public bool IsInfoEnabled => _msLogger.IsEnabled(LogLevel.Information);
-		public bool IsWarnEnabled => _msLogger.IsEnabled(LogLevel.Warning);
 	}
-}
+}

src/NHibernate.Example.Web/Infrastructure/NHibernateToMicrosoftLoggerFactory.cs

@@ -2,7 +2,7 @@
 
 namespace NHibernate.Example.Web.Infrastructure
 {
-	public class NHibernateToMicrosoftLoggerFactory : NHibernate.ILoggerFactory
+	public class NHibernateToMicrosoftLoggerFactory : INHibernateLoggerFactory
 	{
 		private readonly Microsoft.Extensions.Logging.ILoggerFactory _loggerFactory;
 
@@ -11,16 +11,16 @@ public NHibernateToMicrosoftLoggerFactory(Microsoft.Extensions.Logging.ILoggerFa
 			_loggerFactory = loggerFactory ?? throw new ArgumentNullException(nameof(loggerFactory));
 		}
 
-		public IInternalLogger LoggerFor(string keyName)
+		public INHibernateLogger LoggerFor(string keyName)
 		{
 			var msLogger = _loggerFactory.CreateLogger(keyName);
 			return new NHibernateToMicrosoftLogger(msLogger);
 		}
 
-		public IInternalLogger LoggerFor(System.Type type)
+		public INHibernateLogger LoggerFor(System.Type type)
 		{
 			return LoggerFor(
 				Microsoft.Extensions.Logging.Abstractions.Internal.TypeNameHelper.GetTypeDisplayName(type));
 		}
 	}
-}
+}

src/NHibernate.Example.Web/NHibernate.Example.Web.csproj

@@ -14,6 +14,8 @@
     <PackageReference Include="Microsoft.AspNetCore.Mvc" Version="2.0.0" />
     <PackageReference Include="Microsoft.AspNetCore.Mvc.Razor.ViewCompilation" Version="2.0.0" PrivateAssets="All" />
     <PackageReference Include="Microsoft.AspNetCore.StaticFiles" Version="2.0.0" />
+    <PackageReference Include="Serilog.AspNetCore" Version="2.0.0" />
+    <PackageReference Include="Serilog.Sinks.Console" Version="3.1.0" />
   </ItemGroup>
 
   <ItemGroup>

src/NHibernate.Example.Web/Program.cs

@@ -7,19 +7,29 @@
 using Microsoft.AspNetCore.Hosting;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.Logging;
+using Serilog;
+using Serilog.Events;
 
 namespace NHibernate.Example.Web
 {
 	public class Program
 	{
 		public static void Main(string[] args)
 		{
+			Log.Logger = new LoggerConfiguration()
+				.MinimumLevel.Debug()
+				.MinimumLevel.Override("Microsoft", LogEventLevel.Information)
+				.Enrich.FromLogContext()
+				.WriteTo.Console()
+				.CreateLogger();
+
 			BuildWebHost(args).Run();
 		}
 
 		public static IWebHost BuildWebHost(string[] args) =>
 			WebHost.CreateDefaultBuilder(args)
 				.UseStartup<Startup>()
+				.UseSerilog()
 				.Build();
 	}
 }

src/NHibernate.Test/Async/NHSpecificTest/CriteriaFromHql/Fixture.cs

@@ -48,7 +48,7 @@ join fetch c.Children gc
 where p.Parent is null")
 					.UniqueResultAsync<Person>());
 
-				string hqlQuery = spy.Appender.GetEvents()[0].MessageObject.ToString();
+				string hqlQuery = spy.Appender.GetEvents()[0].RenderedMessage;
 				Debug.WriteLine("HQL: " + hqlQuery);
 				Assertions(result);
 			}
@@ -62,7 +62,7 @@ join fetch c.Children gc
 					.SetFetchMode("Children", FetchMode.Join)
 					.SetFetchMode("Children.Children", FetchMode.Join)
 					.UniqueResultAsync<Person>());
-				string criteriaQuery = spy.Appender.GetEvents()[0].MessageObject.ToString();
+				string criteriaQuery = spy.Appender.GetEvents()[0].RenderedMessage;
 				Debug.WriteLine("Criteria: " + criteriaQuery);
 				Assertions(result);
 			}

src/NHibernate.Test/Async/NHSpecificTest/NH1144/Fixture.cs

@@ -64,7 +64,7 @@ public async Task CanSaveInSingleBatchAsync()
 						await (tx.CommitAsync());
 						foreach (LoggingEvent loggingEvent in spy.Appender.GetEvents())
 						{
-							if ("Executing batch".Equals(loggingEvent.MessageObject))
+							if ("Executing batch".Equals(loggingEvent.RenderedMessage))
 							{
 								executedBatch = true;
 								break;

src/NHibernate.Test/Async/NHSpecificTest/NH1347/Fixture.cs

@@ -49,7 +49,7 @@ public async Task BugAsync()
 					.UniqueResultAsync<A>());
 				Assert.AreEqual("1", a.Name);
 				Assert.IsTrue(
-					spy.Appender.GetEvents()[0].MessageObject.ToString().Contains("limit")
+					spy.Appender.GetEvents()[0].RenderedMessage.Contains("limit")
 					);
 			}
 

src/NHibernate.Test/Async/SqlTest/Identity/IdentityInsertWithStoredProcsTest.cs

@@ -51,7 +51,7 @@ public async Task InsertUsesStoredProcAsync()
 
 				Assert.AreEqual(1, spy.Appender.GetEvents().Length, "Num loggedEvents");
 				Assert.AreEqual(1, ifa.Id, "ifa.Id");
-				Assert.AreEqual(GetExpectedInsertOrgLogStatement("IFA"), spy.Appender.GetEvents()[0].MessageObject, "Message 1");
+				Assert.AreEqual(GetExpectedInsertOrgLogStatement("IFA"), spy.Appender.GetEvents()[0].RenderedMessage, "Message 1");
 				using (ISession s = OpenSession())
 				using (ITransaction t = s.BeginTransaction())
 				{
@@ -73,7 +73,7 @@ public async Task InsertUsesStoredProcAsync()
 
 				Assert.AreEqual(1, spy.Appender.GetEvents().Length, "Num loggedEvents");
 				Assert.AreEqual(2, efa.Id, "efa.Id");
-				Assert.AreEqual(GetExpectedInsertOrgLogStatement("EFA"), spy.Appender.GetEvents()[0].MessageObject, "Message 2");
+				Assert.AreEqual(GetExpectedInsertOrgLogStatement("EFA"), spy.Appender.GetEvents()[0].RenderedMessage, "Message 2");
 				using (ISession s = OpenSession())
 				using (ITransaction t = s.BeginTransaction())
 				{