diff --git a/src/NHibernate/AdoNet/AbstractBatcher.cs b/src/NHibernate/AdoNet/AbstractBatcher.cs
index 851f6cf3e12..e295c4f5bfe 100644
--- a/src/NHibernate/AdoNet/AbstractBatcher.cs
+++ b/src/NHibernate/AdoNet/AbstractBatcher.cs
@@ -359,6 +359,8 @@ public void CloseReader(DbDataReader reader)
 			var actualReader = rsw == null ? reader : rsw.Target;
 			_readersToClose.Remove(actualReader);
 
+			var duration = GetReaderStopwatch(actualReader);
+
 			try
 			{
 				reader.Dispose();
@@ -370,17 +372,24 @@ public void CloseReader(DbDataReader reader)
 			}
 
 			LogCloseReader();
+			LogDuration(duration);
+		}
 
-			if (!Log.IsDebugEnabled)
-				return;
-
-			var nhReader = actualReader as NHybridDataReader;
-			actualReader = nhReader == null ? actualReader : nhReader.Target;
+		private Stopwatch GetReaderStopwatch(DbDataReader reader)
+		{
+			var nhReader = reader as NHybridDataReader;
+			var actualReader = nhReader == null ? reader : nhReader.Target;
 
 			Stopwatch duration;
-			if (_readersDuration.TryGetValue(actualReader, out duration) == false)
-				return;
-			_readersDuration.Remove(actualReader);
+			if (_readersDuration.TryGetValue(actualReader, out duration))
+				_readersDuration.Remove(actualReader);
+			return duration;
+		}
+
+		private static void LogDuration(Stopwatch duration)
+		{
+			if (!Log.IsDebugEnabled || duration == null) return;
+
 			Log.DebugFormat("DataReader was closed after {0} ms", duration.ElapsedMilliseconds);
 		}