From 67844165fbd4b799d07cfa4d1b483f1271fa3eb2 Mon Sep 17 00:00:00 2001
From: Roman Artiukhin <bahusdrive@gmail.com>
Date: Mon, 13 Jan 2020 12:28:27 +0200
Subject: [PATCH] Add logging for QueryBatch similar to Loader.DoQuery

---
 src/NHibernate/Async/Multi/QueryBatchItemBase.cs | 13 ++++++++++++-
 src/NHibernate/Multi/QueryBatchItemBase.cs       | 15 ++++++++++++++-
 2 files changed, 26 insertions(+), 2 deletions(-)

diff --git a/src/NHibernate/Async/Multi/QueryBatchItemBase.cs b/src/NHibernate/Async/Multi/QueryBatchItemBase.cs
index cd144051e0f..de34463e521 100644
--- a/src/NHibernate/Async/Multi/QueryBatchItemBase.cs
+++ b/src/NHibernate/Async/Multi/QueryBatchItemBase.cs
@@ -34,6 +34,7 @@ public async Task<int> ProcessResultsSetAsync(DbDataReader reader, CancellationT
 
 			var dialect = Session.Factory.Dialect;
 			var hydratedObjects = new List<object>[_queryInfos.Count];
+			var isDebugLog = Log.IsDebugEnabled();
 
 			using (Session.SwitchCacheMode(_cacheMode))
 			{
@@ -76,8 +77,15 @@ public async Task<int> ProcessResultsSetAsync(DbDataReader reader, CancellationT
 					var optionalObjectKey = Loader.Loader.GetOptionalObjectKey(queryParameters, Session);
 					var tmpResults = new List<object>();
 
-					for (var count = 0; count < maxRows && await (reader.ReadAsync(cancellationToken)).ConfigureAwait(false); count++)
+					if (isDebugLog)
+						Log.Debug("processing result set");
+
+					int count;
+					for (count = 0; count < maxRows && await (reader.ReadAsync(cancellationToken)).ConfigureAwait(false); count++)
 					{
+						if (isDebugLog)
+							Log.Debug("result set row: {0}", count);
+
 						rowCount++;
 
 						var o =
@@ -101,6 +109,9 @@ public async Task<int> ProcessResultsSetAsync(DbDataReader reader, CancellationT
 						tmpResults.Add(o);
 					}
 
+					if (isDebugLog)
+						Log.Debug("done processing result set ({0} rows)", count);
+
 					queryInfo.Result = tmpResults;
 					if (queryInfo.CanPutToCache)
 						queryInfo.ResultToCache = new List<object>(tmpResults);
diff --git a/src/NHibernate/Multi/QueryBatchItemBase.cs b/src/NHibernate/Multi/QueryBatchItemBase.cs
index fa33182327e..b2fdebad2e8 100644
--- a/src/NHibernate/Multi/QueryBatchItemBase.cs
+++ b/src/NHibernate/Multi/QueryBatchItemBase.cs
@@ -16,6 +16,8 @@ namespace NHibernate.Multi
 	/// </summary>
 	public abstract partial class QueryBatchItemBase<TResult> : IQueryBatchItem<TResult>, IQueryBatchItemWithAsyncProcessResults
 	{
+		private static readonly INHibernateLogger Log = NHibernateLogger.For(typeof(QueryBatch));
+
 		protected ISessionImplementor Session;
 		private List<EntityKey[]>[] _subselectResultKeys;
 		private List<QueryInfo> _queryInfos;
@@ -175,6 +177,7 @@ public int ProcessResultsSet(DbDataReader reader)
 
 			var dialect = Session.Factory.Dialect;
 			var hydratedObjects = new List<object>[_queryInfos.Count];
+			var isDebugLog = Log.IsDebugEnabled();
 
 			using (Session.SwitchCacheMode(_cacheMode))
 			{
@@ -217,8 +220,15 @@ public int ProcessResultsSet(DbDataReader reader)
 					var optionalObjectKey = Loader.Loader.GetOptionalObjectKey(queryParameters, Session);
 					var tmpResults = new List<object>();
 
-					for (var count = 0; count < maxRows && reader.Read(); count++)
+					if (isDebugLog)
+						Log.Debug("processing result set");
+
+					int count;
+					for (count = 0; count < maxRows && reader.Read(); count++)
 					{
+						if (isDebugLog)
+							Log.Debug("result set row: {0}", count);
+
 						rowCount++;
 
 						var o =
@@ -242,6 +252,9 @@ public int ProcessResultsSet(DbDataReader reader)
 						tmpResults.Add(o);
 					}
 
+					if (isDebugLog)
+						Log.Debug("done processing result set ({0} rows)", count);
+
 					queryInfo.Result = tmpResults;
 					if (queryInfo.CanPutToCache)
 						queryInfo.ResultToCache = new List<object>(tmpResults);