These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 
Author Message
 Post subject: Hanging at "Obtaining IDbConnection from Driver"
PostPosted: Sun Oct 11, 2009 11:48 pm 
Newbie

Joined: Sun Oct 11, 2009 11:28 pm
Posts: 2
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] &lt;%X{auth}&gt; - %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 (?)]


Top
 Profile  
 
 Post subject: Re: Hanging at "Obtaining IDbConnection from Driver"
PostPosted: Mon Oct 19, 2009 12:51 am 
Newbie

Joined: Sun Oct 11, 2009 11:28 pm
Posts: 2
This turned out to be a windows firewall issue, without the firewall it works fine. Haven't investigated further yet.


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.