I'm using nServiceBus which is a .Net open source library which utilises NHibernate for database access. My programs works perfectly on a number of different computers, however they are not working properly on one particular computer. The weird thing is that the query/action (sorry I just use nServiceBus and am not familiar with internals) works fine under scenario A (where it is invoked by a timer), but fails under scenario B when being invoked by a message handler. From what I can see, it is timing out when trying to obtain the "IDbConnection from Driver".
The only thing I can notice is that in the working execution log (top code segment) what I am assuming is the thread ID (config is <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] <%X{auth}> - %m%n" />) is always the same whilst in the failing execution log (bottom code segment) the thread ID is different.
As I said the code works fine on other computers, so I imagine it's computer specific. Any tips on what could cause this kind of problem?
(the ... are just values I omitted)
EDIT: And I'm not sure why lines are duplicated, it's probably something to do with my logging setup.
Code:
2009-10-12 13:36:54,828 [12] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - [session-id=067e592a-1dc5-4db7-88b9-06ee32a7d52c] opened session at timestamp:633909514148
2009-10-12 13:36:54,828 [12] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - [session-id=067e592a-1dc5-4db7-88b9-06ee32a7d52c] opened session at timestamp:633909514148
2009-10-12 13:36:54,890 [12] DEBUG NHibernate.SqlCommand.SqlSelectBuilder [(null)] <(null)> - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 12 for the table [Subscription] this_
2009-10-12 13:36:54,890 [12] DEBUG NHibernate.SqlCommand.SqlSelectBuilder [(null)] <(null)> - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 12 for the table [Subscription] this_
2009-10-12 13:36:54,921 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Opened new IDbCommand, open IDbCommands: 1
2009-10-12 13:36:54,921 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Opened new IDbCommand, open IDbCommands: 1
2009-10-12 13:36:54,921 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Building an IDbCommand object for the SqlString: SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?)
2009-10-12 13:36:54,921 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Building an IDbCommand object for the SqlString: SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?)
2009-10-12 13:36:54,937 [12] DEBUG NHibernate.Engine.QueryParameters [(null)] <(null)> - BindParameters(Named:NHibernate.Type.StringType) ... -> [0]
2009-10-12 13:36:54,937 [12] DEBUG NHibernate.Engine.QueryParameters [(null)] <(null)> - BindParameters(Named:NHibernate.Type.StringType) ... -> [0]
2009-10-12 13:36:54,937 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - binding '...' to parameter: 0
2009-10-12 13:36:54,937 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - binding '...' to parameter: 0
2009-10-12 13:36:55,140 [12] INFO NHibernate.Loader.Loader [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0)
2009-10-12 13:36:55,140 [12] INFO NHibernate.Loader.Loader [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0)
2009-10-12 13:36:55,140 [12] DEBUG NHibernate.SQL [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0);@p0 = '...'
2009-10-12 13:36:55,140 [12] DEBUG NHibernate.SQL [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0);@p0 = '...'
2009-10-12 13:36:55,343 [12] DEBUG NHibernate.Connection.DriverConnectionProvider [(null)] <(null)> - Obtaining IDbConnection from Driver
2009-10-12 13:36:55,343 [12] DEBUG NHibernate.Connection.DriverConnectionProvider [(null)] <(null)> - Obtaining IDbConnection from Driver
2009-10-12 13:36:55,343 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - ExecuteReader took 0 ms
2009-10-12 13:36:55,343 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - ExecuteReader took 0 ms
2009-10-12 13:36:55,343 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Opened IDataReader, open IDataReaders: 1
2009-10-12 13:36:55,343 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Opened IDataReader, open IDataReaders: 1
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - processing result set
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - processing result set
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 0
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 0
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 1
2009-10-12 13:36:55,546 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 1
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 2
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 2
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,750 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 3
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 3
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 4
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 4
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:55,953 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 5
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 5
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,156 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 6
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 6
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 7
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set row: 7
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:56,359 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row:
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning '...' as column: y0_
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - done processing result set (8 rows)
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - done processing result set (8 rows)
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.Driver.NHybridDataReader [(null)] <(null)> - running NHybridDataReader.Dispose()
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.Driver.NHybridDataReader [(null)] <(null)> - running NHybridDataReader.Dispose()
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Closed IDataReader, open IDataReaders :0
2009-10-12 13:36:56,562 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Closed IDataReader, open IDataReaders :0
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - DataReader was closed after 1419 ms
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - DataReader was closed after 1419 ms
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Closed IDbCommand, open IDbCommands: 0
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Closed IDbCommand, open IDbCommands: 0
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.Connection.ConnectionProvider [(null)] <(null)> - Closing connection
2009-10-12 13:36:56,765 [12] DEBUG NHibernate.Connection.ConnectionProvider [(null)] <(null)> - Closing connection
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.Engine.StatefulPersistenceContext [(null)] <(null)> - initializing non-lazy collections
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.Engine.StatefulPersistenceContext [(null)] <(null)> - initializing non-lazy collections
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.Transform.DistinctRootEntityResultTransformer [(null)] <(null)> - transformed: 8 rows to: 8 distinct results
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.Transform.DistinctRootEntityResultTransformer [(null)] <(null)> - transformed: 8 rows to: 8 distinct results
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - after autocommit
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - after autocommit
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:36:56,968 [12] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:36:57,171 [12] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:36:57,171 [12] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
Code:
2009-10-12 13:49:03,609 [Worker.13] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - [session-id=11e56e64-1072-4c80-bde5-dfe61226977f] opened session at timestamp:633909521435
2009-10-12 13:49:03,609 [Worker.13] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - [session-id=11e56e64-1072-4c80-bde5-dfe61226977f] opened session at timestamp:633909521435
2009-10-12 13:49:03,625 [Worker.13] DEBUG NHibernate.Impl.AbstractSessionImpl [(null)] <(null)> - enlisted into DTC transaction: Serializable
2009-10-12 13:49:03,625 [Worker.13] DEBUG NHibernate.Impl.AbstractSessionImpl [(null)] <(null)> - enlisted into DTC transaction: Serializable
2009-10-12 13:10:19,218 [Worker.13] DEBUG NHibernate.SqlCommand.SqlSelectBuilder [(null)] <(null)> - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 12 for the table [Subscription] this_
2009-10-12 13:10:19,218 [Worker.13] DEBUG NHibernate.SqlCommand.SqlSelectBuilder [(null)] <(null)> - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 12 for the table [Subscription] this_
2009-10-12 13:10:19,265 [Worker.13] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Opened new IDbCommand, open IDbCommands: 1
2009-10-12 13:10:19,265 [Worker.13] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Opened new IDbCommand, open IDbCommands: 1
2009-10-12 13:10:19,265 [Worker.13] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Building an IDbCommand object for the SqlString: SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?)
2009-10-12 13:10:19,265 [Worker.13] DEBUG NHibernate.AdoNet.AbstractBatcher [(null)] <(null)> - Building an IDbCommand object for the SqlString: SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?)
2009-10-12 13:10:19,375 [Worker.13] DEBUG NHibernate.Engine.QueryParameters [(null)] <(null)> - BindParameters(Named:NHibernate.Type.StringType) ... -> [0]
2009-10-12 13:10:19,375 [Worker.13] DEBUG NHibernate.Engine.QueryParameters [(null)] <(null)> - BindParameters(Named:NHibernate.Type.StringType) ... -> [0]
2009-10-12 13:10:19,375 [Worker.13] DEBUG NHibernate.Type.StringType [(null)] <(null)> - binding '...' to parameter: 0
2009-10-12 13:10:19,375 [Worker.13] DEBUG NHibernate.Type.StringType [(null)] <(null)> - binding '...' to parameter: 0
2009-10-12 13:10:19,578 [Worker.13] INFO NHibernate.Loader.Loader [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0)
2009-10-12 13:10:19,578 [Worker.13] INFO NHibernate.Loader.Loader [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0)
2009-10-12 13:10:19,578 [Worker.13] DEBUG NHibernate.SQL [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0);@p0 = '...'
2009-10-12 13:10:19,578 [Worker.13] DEBUG NHibernate.SQL [(null)] <(null)> - SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (@p0);@p0 = '...'
2009-10-12 13:10:19,781 [Worker.13] DEBUG NHibernate.Connection.DriverConnectionProvider [(null)] <(null)> - Obtaining IDbConnection from Driver
2009-10-12 13:10:19,781 [Worker.13] DEBUG NHibernate.Connection.DriverConnectionProvider [(null)] <(null)> - Obtaining IDbConnection from Driver
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.Impl.AbstractSessionImpl [(null)] <(null)> - rolled back DTC transaction
2009-10-12 13:10:37,718 [15] DEBUG NHibernate.Impl.AbstractSessionImpl [(null)] <(null)> - rolled back DTC transaction
2009-10-12 13:10:37,750 [Worker.13] DEBUG NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - SQL Exception
System.Transactions.TransactionException: The transaction has already been implicitly or explicitly committed or aborted. ---> System.Runtime.InteropServices.COMException (0x8004D00E): The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
at System.Transactions.Oletx.ITransactionShim.Export(UInt32 whereaboutsSize, Byte[] whereabouts, Int32& cookieIndex, UInt32& cookieSize, CoTaskMemHandle& cookieBuffer)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
--- End of inner exception stack trace ---
at System.Transactions.Oletx.OletxTransactionManager.ProxyException(COMException comException)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
at System.Data.SqlClient.SqlInternalConnection.GetTransactionCookie(Transaction transaction, Byte[] whereAbouts)
at System.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)
at System.Data.SqlClient.SqlInternalConnection.Enlist(Transaction tx)
at System.Data.SqlClient.SqlInternalConnectionTds.Activate(Transaction transaction)
at System.Data.ProviderBase.DbConnectionInternal.ActivateConnection(Transaction transaction)
at System.Data.ProviderBase.DbConnectionPool.GetConnection(DbConnection owningObject)
at System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection owningConnection)
at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory)
at System.Data.SqlClient.SqlConnection.Open()
at NHibernate.Connection.DriverConnectionProvider.GetConnection()
at NHibernate.AdoNet.ConnectionManager.GetConnection()
at NHibernate.AdoNet.AbstractBatcher.Prepare(IDbCommand cmd)
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
2009-10-12 13:10:37,750 [Worker.13] DEBUG NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - SQL Exception
System.Transactions.TransactionException: The transaction has already been implicitly or explicitly committed or aborted. ---> System.Runtime.InteropServices.COMException (0x8004D00E): The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
at System.Transactions.Oletx.ITransactionShim.Export(UInt32 whereaboutsSize, Byte[] whereabouts, Int32& cookieIndex, UInt32& cookieSize, CoTaskMemHandle& cookieBuffer)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
--- End of inner exception stack trace ---
at System.Transactions.Oletx.OletxTransactionManager.ProxyException(COMException comException)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
at System.Data.SqlClient.SqlInternalConnection.GetTransactionCookie(Transaction transaction, Byte[] whereAbouts)
at System.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)
at System.Data.SqlClient.SqlInternalConnection.Enlist(Transaction tx)
at System.Data.SqlClient.SqlInternalConnectionTds.Activate(Transaction transaction)
at System.Data.ProviderBase.DbConnectionInternal.ActivateConnection(Transaction transaction)
at System.Data.ProviderBase.DbConnectionPool.GetConnection(DbConnection owningObject)
at System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection owningConnection)
at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory)
at System.Data.SqlClient.SqlConnection.Open()
at NHibernate.Connection.DriverConnectionProvider.GetConnection()
at NHibernate.AdoNet.ConnectionManager.GetConnection()
at NHibernate.AdoNet.AbstractBatcher.Prepare(IDbCommand cmd)
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
2009-10-12 13:10:38,531 [Worker.13] WARN NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - System.Transactions.TransactionException: The transaction has already been implicitly or explicitly committed or aborted. ---> System.Runtime.InteropServices.COMException (0x8004D00E): The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
at System.Transactions.Oletx.ITransactionShim.Export(UInt32 whereaboutsSize, Byte[] whereabouts, Int32& cookieIndex, UInt32& cookieSize, CoTaskMemHandle& cookieBuffer)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
--- End of inner exception stack trace ---
at System.Transactions.Oletx.OletxTransactionManager.ProxyException(COMException comException)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
at System.Data.SqlClient.SqlInternalConnection.GetTransactionCookie(Transaction transaction, Byte[] whereAbouts)
at System.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)
at System.Data.SqlClient.SqlInternalConnection.Enlist(Transaction tx)
at System.Data.SqlClient.SqlInternalConnectionTds.Activate(Transaction transaction)
at System.Data.ProviderBase.DbConnectionInternal.ActivateConnection(Transaction transaction)
at System.Data.ProviderBase.DbConnectionPool.GetConnection(DbConnection owningObject)
at System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection owningConnection)
at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory)
at System.Data.SqlClient.SqlConnection.Open()
at NHibernate.Connection.DriverConnectionProvider.GetConnection()
at NHibernate.AdoNet.ConnectionManager.GetConnection()
at NHibernate.AdoNet.AbstractBatcher.Prepare(IDbCommand cmd)
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
2009-10-12 13:10:38,531 [Worker.13] WARN NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - System.Transactions.TransactionException: The transaction has already been implicitly or explicitly committed or aborted. ---> System.Runtime.InteropServices.COMException (0x8004D00E): The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
at System.Transactions.Oletx.ITransactionShim.Export(UInt32 whereaboutsSize, Byte[] whereabouts, Int32& cookieIndex, UInt32& cookieSize, CoTaskMemHandle& cookieBuffer)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
--- End of inner exception stack trace ---
at System.Transactions.Oletx.OletxTransactionManager.ProxyException(COMException comException)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
at System.Data.SqlClient.SqlInternalConnection.GetTransactionCookie(Transaction transaction, Byte[] whereAbouts)
at System.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)
at System.Data.SqlClient.SqlInternalConnection.Enlist(Transaction tx)
at System.Data.SqlClient.SqlInternalConnectionTds.Activate(Transaction transaction)
at System.Data.ProviderBase.DbConnectionInternal.ActivateConnection(Transaction transaction)
at System.Data.ProviderBase.DbConnectionPool.GetConnection(DbConnection owningObject)
at System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection owningConnection)
at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory)
at System.Data.SqlClient.SqlConnection.Open()
at NHibernate.Connection.DriverConnectionProvider.GetConnection()
at NHibernate.AdoNet.ConnectionManager.GetConnection()
at NHibernate.AdoNet.AbstractBatcher.Prepare(IDbCommand cmd)
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
2009-10-12 13:10:39,343 [Worker.13] ERROR NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - The transaction has already been implicitly or explicitly committed or aborted.
2009-10-12 13:10:39,343 [Worker.13] ERROR NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - The transaction has already been implicitly or explicitly committed or aborted.
2009-10-12 13:10:39,546 [Worker.13] WARN NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - System.Runtime.InteropServices.COMException (0x8004D00E): The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
at System.Transactions.Oletx.ITransactionShim.Export(UInt32 whereaboutsSize, Byte[] whereabouts, Int32& cookieIndex, UInt32& cookieSize, CoTaskMemHandle& cookieBuffer)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
2009-10-12 13:10:39,546 [Worker.13] WARN NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - System.Runtime.InteropServices.COMException (0x8004D00E): The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
at System.Transactions.Oletx.ITransactionShim.Export(UInt32 whereaboutsSize, Byte[] whereabouts, Int32& cookieIndex, UInt32& cookieSize, CoTaskMemHandle& cookieBuffer)
at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
2009-10-12 13:10:39,750 [Worker.13] ERROR NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
2009-10-12 13:10:39,750 [Worker.13] ERROR NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - The transaction has already been implicitly or explicitly committed or aborted (Exception from HRESULT: 0x8004D00E)
2009-10-12 13:10:39,750 [Worker.13] DEBUG NHibernate.Impl.AbstractSessionImpl [(null)] <(null)> - enlisted into DTC transaction: Serializable
2009-10-12 13:10:39,750 [Worker.13] DEBUG NHibernate.Impl.AbstractSessionImpl [(null)] <(null)> - enlisted into DTC transaction: Serializable
2009-10-12 13:10:39,750 [Worker.13] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:10:39,750 [Worker.13] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2009-10-12 13:10:39,953 [Worker.13] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:10:39,953 [Worker.13] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - aggressively releasing database connection
2009-10-12 13:10:39,953 [Worker.13] DEBUG NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - could not execute query
[ SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?) ]
Positional parameters: #0>...
System.Transactions.TransactionException: The operation is not valid for the state of the transaction.
at System.Transactions.TransactionState.EnlistVolatile(InternalTransaction tx, IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions, Transaction atomicTransaction)
at System.Transactions.Transaction.EnlistVolatile(IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions)
at NHibernate.Transaction.AdoNetWithDistrubtedTransactionFactory.EnlistInDistributedTransactionIfNeeded(ISessionImplementor session)
at NHibernate.Impl.AbstractSessionImpl.EnlistInAmbientTransactionIfNeeded()
at NHibernate.Impl.AbstractSessionImpl.CheckAndUpdateSessionStatus()
at NHibernate.Impl.SessionImpl.get_Batcher()
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
at NHibernate.Loader.Loader.DoQuery(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters)
2009-10-12 13:10:39,953 [Worker.13] DEBUG NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - could not execute query
[ SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?) ]
Positional parameters: #0>...
System.Transactions.TransactionException: The operation is not valid for the state of the transaction.
at System.Transactions.TransactionState.EnlistVolatile(InternalTransaction tx, IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions, Transaction atomicTransaction)
at System.Transactions.Transaction.EnlistVolatile(IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions)
at NHibernate.Transaction.AdoNetWithDistrubtedTransactionFactory.EnlistInDistributedTransactionIfNeeded(ISessionImplementor session)
at NHibernate.Impl.AbstractSessionImpl.EnlistInAmbientTransactionIfNeeded()
at NHibernate.Impl.AbstractSessionImpl.CheckAndUpdateSessionStatus()
at NHibernate.Impl.SessionImpl.get_Batcher()
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
at NHibernate.Loader.Loader.DoQuery(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters)
2009-10-12 13:10:40,562 [Worker.13] WARN NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - System.Transactions.TransactionException: The operation is not valid for the state of the transaction.
at System.Transactions.TransactionState.EnlistVolatile(InternalTransaction tx, IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions, Transaction atomicTransaction)
at System.Transactions.Transaction.EnlistVolatile(IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions)
at NHibernate.Transaction.AdoNetWithDistrubtedTransactionFactory.EnlistInDistributedTransactionIfNeeded(ISessionImplementor session)
at NHibernate.Impl.AbstractSessionImpl.EnlistInAmbientTransactionIfNeeded()
at NHibernate.Impl.AbstractSessionImpl.CheckAndUpdateSessionStatus()
at NHibernate.Impl.SessionImpl.get_Batcher()
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
at NHibernate.Loader.Loader.DoQuery(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters)
2009-10-12 13:10:40,562 [Worker.13] WARN NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - System.Transactions.TransactionException: The operation is not valid for the state of the transaction.
at System.Transactions.TransactionState.EnlistVolatile(InternalTransaction tx, IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions, Transaction atomicTransaction)
at System.Transactions.Transaction.EnlistVolatile(IEnlistmentNotification enlistmentNotification, EnlistmentOptions enlistmentOptions)
at NHibernate.Transaction.AdoNetWithDistrubtedTransactionFactory.EnlistInDistributedTransactionIfNeeded(ISessionImplementor session)
at NHibernate.Impl.AbstractSessionImpl.EnlistInAmbientTransactionIfNeeded()
at NHibernate.Impl.AbstractSessionImpl.CheckAndUpdateSessionStatus()
at NHibernate.Impl.SessionImpl.get_Batcher()
at NHibernate.Loader.Loader.GetResultSet(IDbCommand st, BooleanA first chance exception of type 'NHibernate.ADOException' occurred in NServiceBus.Core.dll
autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session)
at NHibernate.Loader.Loader.DoQuery(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies)
at NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters)
2009-10-12 13:10:41,171 [Worker.13] ERROR NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - The operation is not valid for the state of the transaction.
2009-10-12 13:10:41,171 [Worker.13] ERROR NHibernate.Util.ADOExceptionReporter [(null)] <(null)> - The operation is not valid for the state of the transaction.
2009-10-12 13:10:41,171 [Worker.13] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - after autocommit
2009-10-12 13:10:41,171 [Worker.13] DEBUG NHibernate.AdoNet.ConnectionManager [(null)] <(null)> - after autocoEXCEPTION: BusLib.HeartbeatMachine.SendHeartbeat() - could not execute query
[ SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?) ]
Positional parameters: #0>...
[SQL: SELECT this_.SubscriberEndpoint as y0_ FROM [Subscription] this_ WHERE this_.MessageType in (?)]