Menu
▾
▴
[Nhibernate-commit] SF.net SVN: nhibernate:[4514] trunk/nhibernate
|
From: <aye...@us...> - 2009-06-23 06:11:06
|
Revision: 4514
http://nhibernate.svn.sourceforge.net/nhibernate/?rev=4514&view=rev
Author: ayenderahien
Date: 2009-06-23 06:09:34 +0000 (Tue, 23 Jun 2009)
Log Message:
-----------
Merging from 2.1.x branch:
- Made openCommandCount and openReaderCount thread safe
- Fixed NH-1850 NHibernate should log query duration
- Made LogSpy output easier to read for humans
- Avoiding sync overhead when it is not needed for WrapResultSet
Modified Paths:
--------------
trunk/nhibernate/src/NHibernate/AdoNet/AbstractBatcher.cs
trunk/nhibernate/src/NHibernate/Driver/NHybridDataReader.cs
trunk/nhibernate/src/NHibernate/Loader/Loader.cs
trunk/nhibernate/src/NHibernate.Test/LogSpy.cs
trunk/nhibernate/src/NHibernate.Test/NHibernate.Test.csproj
Added Paths:
-----------
trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/
trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs
trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs
trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml
Removed Paths:
-------------
trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs
trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs
trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml
Property Changed:
----------------
trunk/nhibernate/lib/net/3.5/
trunk/nhibernate/src/NHibernate.Test/Tools/hbm2ddl/SchemaExportTests/
Property changes on: trunk/nhibernate/lib/net/3.5
___________________________________________________________________
Added: svn:ignore
+ NHibernate.dll
Modified: trunk/nhibernate/src/NHibernate/AdoNet/AbstractBatcher.cs
===================================================================
--- trunk/nhibernate/src/NHibernate/AdoNet/AbstractBatcher.cs 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate/AdoNet/AbstractBatcher.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -12,6 +12,10 @@
namespace NHibernate.AdoNet
{
+ using System.Collections.Generic;
+ using System.Diagnostics;
+ using System.Threading;
+
/// <summary>
/// Manages prepared statements and batching. Class exists to enforce separation of concerns
/// </summary>
@@ -34,6 +38,7 @@
private readonly ISet<IDbCommand> commandsToClose = new HashedSet<IDbCommand>();
private readonly ISet<IDataReader> readersToClose = new HashedSet<IDataReader>();
+ private readonly IDictionary<IDataReader, Stopwatch> readersDuration = new Dictionary<IDataReader, Stopwatch>();
private IDbCommand lastQuery;
private bool releasing;
@@ -197,7 +202,10 @@
{
CheckReaders();
Prepare(cmd);
- try
+ Stopwatch duration = null;
+ if(log.IsDebugEnabled)
+ duration = Stopwatch.StartNew();
+ try
{
return cmd.ExecuteNonQuery();
}
@@ -207,14 +215,21 @@
log.Error("Could not execute command: " + cmd.CommandText, e);
throw;
}
+ finally
+ {
+ if (log.IsDebugEnabled && duration != null)
+ log.DebugFormat("ExecuteNonQuery took {0} ms", duration.ElapsedMilliseconds);
+ }
}
public IDataReader ExecuteReader(IDbCommand cmd)
{
CheckReaders();
Prepare(cmd);
-
- IDataReader reader;
+ Stopwatch duration = null;
+ if (log.IsDebugEnabled)
+ duration = Stopwatch.StartNew();
+ IDataReader reader = null;
try
{
reader = cmd.ExecuteReader();
@@ -225,6 +240,14 @@
log.Error("Could not execute query: " + cmd.CommandText, e);
throw;
}
+ finally
+ {
+ if(log.IsDebugEnabled && duration != null && reader != null)
+ {
+ log.DebugFormat("ExecuteReader took {0} ms", duration.ElapsedMilliseconds);
+ readersDuration[reader] = duration;
+ }
+ }
if (!factory.ConnectionProvider.Driver.SupportsMultipleOpenReaders)
{
@@ -259,19 +282,17 @@
releasing = true;
try
{
- foreach (IDataReader reader in readersToClose)
+ foreach (IDataReader reader in new HashedSet<IDataReader>(readersToClose))
{
try
{
- LogCloseReader();
- reader.Dispose();
+ CloseReader(reader);
}
catch (Exception e)
{
log.Warn("Could not close IDataReader", e);
}
}
- readersToClose.Clear();
foreach (IDbCommand cmd in commandsToClose)
{
@@ -343,18 +364,26 @@
*/
// TODO NH: Study a way to use directly IDbCommand.ExecuteReader() outsite the batcher
// An example of it's use is the management of generated ID.
- if (reader != null)
- {
- ResultSetWrapper rsw = reader as ResultSetWrapper;
- readersToClose.Remove(rsw == null ? reader : rsw.Target);
- CloseDataReader(reader);
- }
- }
+ if (reader == null)
+ return;
- private void CloseDataReader(IDataReader reader)
- {
+ ResultSetWrapper rsw = reader as ResultSetWrapper;
+ var actualReader = rsw == null ? reader : rsw.Target;
+ readersToClose.Remove(actualReader);
reader.Dispose();
LogCloseReader();
+
+ if (!log.IsDebugEnabled)
+ return;
+
+ var nhReader = actualReader as NHybridDataReader;
+ actualReader = nhReader == null ? actualReader : nhReader.Target;
+
+ Stopwatch duration;
+ if (readersDuration.TryGetValue(actualReader, out duration)==false)
+ return;
+ readersDuration.Remove(actualReader);
+ log.DebugFormat("DataReader was closed after {0} ms", duration.ElapsedMilliseconds);
}
/// <summary></summary>
@@ -434,8 +463,8 @@
{
if (log.IsDebugEnabled)
{
- openCommandCount++;
- log.Debug("Opened new IDbCommand, open IDbCommands: " + openCommandCount);
+ int currentOpenCommandCount = Interlocked.Increment(ref openCommandCount);
+ log.Debug("Opened new IDbCommand, open IDbCommands: " + currentOpenCommandCount);
}
if (factory.Statistics.IsStatisticsEnabled)
@@ -448,8 +477,8 @@
{
if (log.IsDebugEnabled)
{
- openCommandCount--;
- log.Debug("Closed IDbCommand, open IDbCommands: " + openCommandCount);
+ int currentOpenCommandCount = Interlocked.Decrement(ref openCommandCount);
+ log.Debug("Closed IDbCommand, open IDbCommands: " + currentOpenCommandCount);
}
if (factory.Statistics.IsStatisticsEnabled)
@@ -462,8 +491,8 @@
{
if (log.IsDebugEnabled)
{
- openReaderCount++;
- log.Debug("Opened IDataReader, open IDataReaders: " + openReaderCount);
+ int currentOpenReaderCount = Interlocked.Increment(ref openReaderCount);
+ log.Debug("Opened IDataReader, open IDataReaders: " + currentOpenReaderCount);
}
}
@@ -471,8 +500,8 @@
{
if (log.IsDebugEnabled)
{
- openReaderCount--;
- log.Debug("Closed IDataReader, open IDataReaders :" + openReaderCount);
+ int currentOpenReaderCount = Interlocked.Decrement(ref openReaderCount);
+ log.Debug("Closed IDataReader, open IDataReaders :" + currentOpenReaderCount);
}
}
Modified: trunk/nhibernate/src/NHibernate/Driver/NHybridDataReader.cs
===================================================================
--- trunk/nhibernate/src/NHibernate/Driver/NHybridDataReader.cs 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate/Driver/NHybridDataReader.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -27,6 +27,8 @@
private IDataReader _reader;
private bool _isMidstream = false;
+ public IDataReader Target { get { return _reader; } }
+
/// <summary>
/// Initializes a new instance of the <see cref="NHybridDataReader"/> class.
/// </summary>
Modified: trunk/nhibernate/src/NHibernate/Loader/Loader.cs
===================================================================
--- trunk/nhibernate/src/NHibernate/Loader/Loader.cs 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate/Loader/Loader.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -1297,8 +1297,13 @@
log.Info(st.CommandText);
// TODO NH: Callable
rs = session.Batcher.ExecuteReader(st);
- rs = WrapResultSetIfEnabled(rs, session);
+ //NH: this is checked outside the WrapResultSet because we
+ // want to avoid the syncronization overhead in the vast majority
+ // of cases where IsWrapResultSetsEnabled is set to false
+ if (session.Factory.Settings.IsWrapResultSetsEnabled)
+ rs = WrapResultSet(rs);
+
Dialect.Dialect dialect = session.Factory.Dialect;
if (!dialect.SupportsLimitOffset || !UseLimit(selection, dialect))
{
@@ -1325,25 +1330,18 @@
}
[MethodImpl(MethodImplOptions.Synchronized)]
- private IDataReader WrapResultSetIfEnabled(IDataReader rs, ISessionImplementor session)
+ private IDataReader WrapResultSet(IDataReader rs)
{
// synchronized to avoid multi-thread access issues; defined as method synch to avoid
// potential deadlock issues due to nature of code.
- if (session.Factory.Settings.IsWrapResultSetsEnabled)
+ try
{
- try
- {
- log.Debug("Wrapping result set [" + rs + "]");
- return new ResultSetWrapper(rs, RetreiveColumnNameToIndexCache(rs));
- }
- catch (Exception e)
- {
- log.Info("Error wrapping result set", e);
- return rs;
- }
+ log.Debug("Wrapping result set [" + rs + "]");
+ return new ResultSetWrapper(rs, RetreiveColumnNameToIndexCache(rs));
}
- else
+ catch (Exception e)
{
+ log.Info("Error wrapping result set", e);
return rs;
}
}
Modified: trunk/nhibernate/src/NHibernate.Test/LogSpy.cs
===================================================================
--- trunk/nhibernate/src/NHibernate.Test/LogSpy.cs 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate.Test/LogSpy.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -56,7 +56,8 @@
wholeMessage
.Append(loggingEvent.LoggerName)
.Append(" ")
- .Append(loggingEvent.RenderedMessage);
+ .Append(loggingEvent.RenderedMessage)
+ .AppendLine();
}
return wholeMessage.ToString();
}
Deleted: trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs
===================================================================
--- branches/2.1.x/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -1,12 +0,0 @@
-using System;
-using System.Collections.Generic;
-using System.Text;
-
-namespace NHibernate.Test.NHSpecificTest.NH1850
-{
- public class Customer
- {
- public virtual int Id { get; set; }
- public virtual string Name { get; set; }
- }
-}
Copied: trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs (from rev 4513, branches/2.1.x/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs)
===================================================================
--- trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs (rev 0)
+++ trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Customer.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -0,0 +1,12 @@
+using System;
+using System.Collections.Generic;
+using System.Text;
+
+namespace NHibernate.Test.NHSpecificTest.NH1850
+{
+ public class Customer
+ {
+ public virtual int Id { get; set; }
+ public virtual string Name { get; set; }
+ }
+}
Deleted: trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs
===================================================================
--- branches/2.1.x/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -1,53 +0,0 @@
-using System;
-using System.Collections.Generic;
-using System.Text;
-using NHibernate.Criterion;
-using NUnit.Framework;
-
-namespace NHibernate.Test.NHSpecificTest.NH1850
-{
- using AdoNet;
-
- [TestFixture]
- public class Fixture:BugTestCase
- {
- [Test]
- public void CanGetQueryDurationForDelete()
- {
- using (LogSpy spy = new LogSpy(typeof(AbstractBatcher)))
- using (ISession session = OpenSession())
- using (ITransaction tx = session.BeginTransaction())
- {
- session.CreateQuery("delete Customer").ExecuteUpdate();
-
- var wholeLog = spy.GetWholeLog();
- Assert.True(
- wholeLog.Contains("ExecuteNonQuery took")
- );
-
- tx.Rollback();
- }
- }
-
- [Test]
- public void CanGetQueryDurationForSelect()
- {
- using (LogSpy spy = new LogSpy(typeof(AbstractBatcher)))
- using (ISession session = OpenSession())
- using (ITransaction tx = session.BeginTransaction())
- {
- session.CreateQuery("from Customer").List();
-
- var wholeLog = spy.GetWholeLog();
- Assert.True(
- wholeLog.Contains("ExecuteReader took")
- );
- Assert.True(
- wholeLog.Contains("DataReader was closed after")
- );
-
- tx.Rollback();
- }
- }
- }
-}
Copied: trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs (from rev 4513, branches/2.1.x/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs)
===================================================================
--- trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs (rev 0)
+++ trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Fixture.cs 2009-06-23 06:09:34 UTC (rev 4514)
@@ -0,0 +1,53 @@
+using System;
+using System.Collections.Generic;
+using System.Text;
+using NHibernate.Criterion;
+using NUnit.Framework;
+
+namespace NHibernate.Test.NHSpecificTest.NH1850
+{
+ using AdoNet;
+
+ [TestFixture]
+ public class Fixture:BugTestCase
+ {
+ [Test]
+ public void CanGetQueryDurationForDelete()
+ {
+ using (LogSpy spy = new LogSpy(typeof(AbstractBatcher)))
+ using (ISession session = OpenSession())
+ using (ITransaction tx = session.BeginTransaction())
+ {
+ session.CreateQuery("delete Customer").ExecuteUpdate();
+
+ var wholeLog = spy.GetWholeLog();
+ Assert.True(
+ wholeLog.Contains("ExecuteNonQuery took")
+ );
+
+ tx.Rollback();
+ }
+ }
+
+ [Test]
+ public void CanGetQueryDurationForSelect()
+ {
+ using (LogSpy spy = new LogSpy(typeof(AbstractBatcher)))
+ using (ISession session = OpenSession())
+ using (ITransaction tx = session.BeginTransaction())
+ {
+ session.CreateQuery("from Customer").List();
+
+ var wholeLog = spy.GetWholeLog();
+ Assert.True(
+ wholeLog.Contains("ExecuteReader took")
+ );
+ Assert.True(
+ wholeLog.Contains("DataReader was closed after")
+ );
+
+ tx.Rollback();
+ }
+ }
+ }
+}
Deleted: trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml
===================================================================
--- branches/2.1.x/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml 2009-06-23 06:09:34 UTC (rev 4514)
@@ -1,13 +0,0 @@
-<?xml version="1.0" encoding="utf-8" ?>
-<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" assembly="NHibernate.Test"
- namespace="NHibernate.Test.NHSpecificTest.NH1850"
- default-lazy="false">
-
- <class name="Customer">
- <id name="Id">
- <generator class="native"/>
- </id>
- <property name="Name"/>
-
- </class>
-</hibernate-mapping>
\ No newline at end of file
Copied: trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml (from rev 4513, branches/2.1.x/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml)
===================================================================
--- trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml (rev 0)
+++ trunk/nhibernate/src/NHibernate.Test/NHSpecificTest/NH1850/Mappings.hbm.xml 2009-06-23 06:09:34 UTC (rev 4514)
@@ -0,0 +1,13 @@
+<?xml version="1.0" encoding="utf-8" ?>
+<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" assembly="NHibernate.Test"
+ namespace="NHibernate.Test.NHSpecificTest.NH1850"
+ default-lazy="false">
+
+ <class name="Customer">
+ <id name="Id">
+ <generator class="native"/>
+ </id>
+ <property name="Name"/>
+
+ </class>
+</hibernate-mapping>
\ No newline at end of file
Modified: trunk/nhibernate/src/NHibernate.Test/NHibernate.Test.csproj
===================================================================
--- trunk/nhibernate/src/NHibernate.Test/NHibernate.Test.csproj 2009-06-23 05:57:17 UTC (rev 4513)
+++ trunk/nhibernate/src/NHibernate.Test/NHibernate.Test.csproj 2009-06-23 06:09:34 UTC (rev 4514)
@@ -527,6 +527,8 @@
<Compile Include="NHSpecificTest\NH1837\Customer.cs" />
<Compile Include="NHSpecificTest\NH1837\Fixture.cs" />
<Compile Include="NHSpecificTest\NH1837\Order.cs" />
+ <Compile Include="NHSpecificTest\NH1850\Customer.cs" />
+ <Compile Include="NHSpecificTest\NH1850\Fixture.cs" />
<Compile Include="NHSpecificTest\NH473\Child.cs" />
<Compile Include="NHSpecificTest\NH473\Fixture.cs" />
<Compile Include="NHSpecificTest\NH473\Parent.cs" />
@@ -1937,6 +1939,7 @@
<EmbeddedResource Include="Bytecode\Lightweight\ProductLine.hbm.xml" />
<EmbeddedResource Include="DriverTest\MultiTypeEntity.hbm.xml" />
<Content Include="DynamicEntity\package.html" />
+ <EmbeddedResource Include="NHSpecificTest\NH1850\Mappings.hbm.xml" />
<EmbeddedResource Include="NHSpecificTest\NH1192\Mappings.hbm.xml" />
<EmbeddedResource Include="NHSpecificTest\NH1734\Mappings.hbm.xml" />
<EmbeddedResource Include="NHSpecificTest\NH1097\Mappings.hbm.xml" />
Property changes on: trunk/nhibernate/src/NHibernate.Test/Tools/hbm2ddl/SchemaExportTests
___________________________________________________________________
Modified: svn:mergeinfo
- /branches/2.1.x/nhibernate/src/NHibernate.Test/Tools/hbm2ddl/SchemaExportTests:4507-4508
+ /branches/2.1.x/nhibernate/src/NHibernate.Test/Tools/hbm2ddl/SchemaExportTests:4507-4508,4510-4513
This was sent by the SourceForge.net collaborative development platform, the world's largest Open Source development site.
|
