Deadlock issues

Topics: Troubleshooting, Writing modules
Feb 14, 2012 at 3:05 PM

Can someone direct me into a right direction regarding my problem?

The situation (which can't be changed)
My module integrates with a wcf service
That wcf service calls an wcf service exposed by our module
When a user request a page it waits for the process to be completed, but that process'll result into a deadlock on the content functionality.

For some situations i worked around this by using repository's directly and avoiding the contentManager.
Using repository's directly results into bugs because versioning is in place, and that content table is locked.

The question
Is it possible to reuse a workcontext / open hibernate session / connection?
If it's possible (which must be) where do i have to look and does anyone have any idea's?

Feb 15, 2012 at 9:08 AM

Or tell hibernate to go into a less restrictive isolation level in specific situations?

Feb 15, 2012 at 10:01 AM

Oke, some more detail

I see 2 possible solutions, 1 is trying to change the transactionscope isolation level in my controller

A repository uses a SessionLocator which holds a open session. If there isn't a open session TransactionManager seems to create a TransactionScope with the IsolationLevel set to ReadCommitted. In my controller i could create a own TransactionScope with a isolationLevel of ReadUnCommitted before even creating my contentitem, but would that be the way to go? Would it be recommended? I noticed that each Repository will get a own session for a differend record, the DefaultContentQuery opens a own session for the ContentItemVersionRecord, etc..

The 2nd solution:

Passing along the transaction with WCF Transaction Propagation using the TransactionFlow attribute. The only problem i'll have there is that the in the wcf service is multi-treaded because it's inside a workflow (windows workflow foundation) with lots of activity's. One of the activity's will need to reuse propagate the transaction towards the service being called into orchard where the deadlock is detected. Then i could use WorkflowExtensions but omg so much work for just fixing a deadlock issue.

Crap :)

Coordinator
Feb 15, 2012 at 5:03 PM

Did you try changing the default isolation level in the Transaction Manager ? Only supported with SQL Server though

Feb 15, 2012 at 5:32 PM
I tried yes and changed it to choas bit using SQL profiler i still das connections opening with serializeable transaction. Several types.. strange
--
Verzonden van mijn Android telefoon met K-9 Mail.

sebastienros <notifications@codeplex.com> schreef:

From: sebastienros

Did you try changing the default isolation level in the Transaction Manager ? Only supported with SQL Server though

Feb 18, 2012 at 2:22 PM

I made sure that there was no other program connecting to the database and used SQL profiler. When i'm back at work i could post some profiling results in here showing that there are connection open with a serializeable transaction.

I tryed solution one, including your suggestion sebastien, changing the default isolation level. Solution 2 might be possible but in that case i'll still have problems when another thread in the pool or another service or so wants to query data.

What we've done wrong, i think, is using ContentManager.Create in a request instead of ContentManager.New, thus inserting data locking it before the in orchard exposed webservice is being called from the middle-tier. I can't just change it to .New because we expect the content item to be created at that moment, changing it'll require some time.

So now i'm left with 3 options:

1. using wcf transaction propagation (not my favorite)
2. using async functionality (AsyncController or wait for async / await)
3. spend alot of time into fixing so it won't insert data in a request, moving it into the post.

Is there a option i'm forgetting? I don't care about phantom reads, lock free would be best, but read uncommited data would be fine as well.

Feb 21, 2012 at 7:46 AM

Somehow i might have forgotten to restart IIS or so, it's still a very low chance that there is a deadlock now, like 99.9% of the time no lock using a transaction with IsolationLevel ReadUncommited.

What does NHibernate do when there isn't a TransactionScope? Does it start a transaction with IsolationLevel Serializeable?

Would it be possible that a reference is keeping ISession alive but that the connection inside the NHibernate ISession can be closed?

Looking at the SessionLocator it only starts a new transaction whenever the session is null.

            if (_session == null) {

                var sessionFactory = _sessionFactoryHolder.GetSessionFactory();

                _transactionManager.Demand();

                Logger.Information("Openning database session");
                _session = sessionFactory.OpenSession(new SessionInterceptor(this));
            }

A check for _session.IsOpen could fix the 0.1%

Coordinator
Feb 22, 2012 at 12:36 AM

When there isn't a transaction scope yet, TransactionManager demands a new one. Please open a bug if you think there is an issue that needs to be fixed here.

Feb 22, 2012 at 9:03 AM
Edited Feb 22, 2012 at 9:08 AM

I'm getting frustrated, it looked gone but now it's back, so i created a workitem http://orchard.codeplex.com/workitem/18457

I did put Orchard on a own application pool so i know for sure that the profile results are from Orchard connecting to SQL Server.

How can it be that:

I see a RPC:Completed doing exec sp_reset_connection
and at the same moment i still see Audit login's this way
which is 100% sure the cause of the deadlock's

-- network protocol: LPC
....
set transaction isolation level serializable

most of the time it's

-- network protocol: LPC
....
set transaction isolation level read uncommitted
Feb 22, 2012 at 9:20 AM
Edited Feb 22, 2012 at 9:25 AM

It looks like the ScheduledTaskExecutor is opening connections outside the transactionscope or something and executes query's in osolation level serializable.

this would be the queries locking the content table, right after opening the connection

exec sp_executesql N'SELECT this_.Id as Id45_0_, this_.TaskType as TaskType45_0_, this_.ScheduledUtc as Schedule3_45_0_, this_.ContentItemVersionRecord_id as ContentI4_45_0_ FROM Scheduling_ScheduledTaskRecord this_ WHERE this_.ScheduledUtc <= @p0',N'@p0 datetime',@p0='2012-02-22 10:19:37'

exec sp_executesql N'SELECT this_.Id as Id52_1_, this_.Title as Title52_1_, this_.Slug as Slug52_1_, this_.Path as Path52_1_, this_.ContentItemRecord_id as ContentI5_52_1_, contentite1_.Id as Id82_0_, contentite1_.Number as Number82_0_, contentite1_.Published as Published82_0_, contentite1_.Latest as Latest82_0_, contentite1_.Data as Data82_0_, contentite1_.ContentItemRecord_id as ContentI6_82_0_ FROM Routable_RoutePartRecord this_ left outer join Orchard_Framework_ContentItemVersionRecord contentite1_ on this_.Id=contentite1_.Id WHERE ((contentite1_.Published = @p0 and not (this_.Path = @p1)) and this_.Path is not null)',N'@p0 bit,@p1 nvarchar(4000)',@p0=1,@p1=N''

and this

exec sp_executesql N'SELECT this_.Id as Id82_3_, this_.Number as Number82_3_, this_.Published as Published82_3_, this_.Latest as Latest82_3_, this_.Data as Data82_3_, this_.ContentItemRecord_id as ContentI6_82_3_, routepartr1_.Id as Id52_0_, routepartr1_.Title as Title52_0_, routepartr1_.Slug as Slug52_0_, routepartr1_.Path as Path52_0_, routepartr1_.ContentItemRecord_id as ContentI5_52_0_, contentite2_.Id as Id83_1_, contentite2_.Data as Data83_1_, contentite2_.ContentType_id as ContentT3_83_1_, containerp3_.Id as Id53_2_, containerp3_.ItemContentType as ItemCont2_53_2_, containerp3_.Paginated as Paginated53_2_, containerp3_.PageSize as PageSize53_2_, containerp3_.OrderByProperty as OrderByP5_53_2_, containerp3_.OrderByDirection as OrderByD6_53_2_ FROM Orchard_Framework_ContentItemVersionRecord this_ inner join Routable_RoutePartRecord routepartr1_ on this_.Id=routepartr1_.Id inner join Orchard_Framework_ContentItemRecord contentite2_ on this_.ContentItemRecord_id=contentite2_.Id inner join Containers_ContainerPartRecord containerp3_ on contentite2_.Id=containerp3_.Id WHERE this_.Published = @p0',N'@p0 bit',@p0=1

Feb 22, 2012 at 9:41 AM

I removed the whole Sweep method implementation just to test it out, the result: no more locks

Coordinator
Feb 22, 2012 at 5:23 PM

Could you try with this in BackgrounService:

 

        public void Sweep() {
            foreach(var task in _tasks.OfType<IBackgroundTask>()) {
                using (var scope = new TransactionScope(TransactionScopeOption.RequiresNew)) {
                    try {
                        task.Sweep();
                        scope.Complete();
                    }
                    catch (Exception e) {
                        Logger.Error(e, "Error while processing background task");
                    }
                }
            }
        }
And also this in SweepGenerator:

        public void DoWork() {
            using (var scope = _workContextAccessor.CreateWorkContextScope()) {
                var transactionManager = scope.Resolve<ITransactionManager>();
                transactionManager.Demand();

                // resolve the manager and invoke it
                var manager = scope.Resolve<IBackgroundService>();
                manager.Sweep();
            }
        }

This is the current code changes I made for 1.x. It might solve the issue.

Mar 15, 2015 at 12:06 PM
Edited Mar 15, 2015 at 12:32 PM
Does the solution fix your problem?
We have a similar problem (you can see the detail https://orchard.codeplex.com/workitem/21266).
Mar 16, 2015 at 6:37 AM
I've test the code but here is the error:

NHibernate.TransactionException was unhandled by user code
HResult=-2146232832
Message=Transaction not connected, or was disconnected
Source=NHibernate
StackTrace:
   at NHibernate.Transaction.AdoTransaction.CheckNotZombied() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Transaction\AdoTransaction.cs:line 412
   at NHibernate.Transaction.AdoTransaction.Commit() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Transaction\AdoTransaction.cs:line 186
   at Orchard.Data.SessionLocator.DisposeSession() in d:\Projects\Orchard-Git\orchard\src\Orchard\Data\SessionLocator.cs:line 75
   at Orchard.Data.SessionLocator.Dispose() in d:\Projects\Orchard-Git\orchard\src\Orchard\Data\SessionLocator.cs:line 66
   at Autofac.Core.Disposer.Dispose(Boolean disposing) in c:\Projects\OSS\autofac\Core\Source\Autofac\Core\Disposer.cs:line 58
   at Autofac.Util.Disposable.Dispose() in c:\Projects\OSS\autofac\Core\Source\Autofac\Util\Disposable.cs:line 51
   at Autofac.Core.Lifetime.LifetimeScope.Dispose(Boolean disposing) in c:\Projects\OSS\autofac\Core\Source\Autofac\Core\Lifetime\LifetimeScope.cs:line 318
   at Autofac.Util.Disposable.Dispose() in c:\Projects\OSS\autofac\Core\Source\Autofac\Util\Disposable.cs:line 51
   at Orchard.Environment.WorkContextAccessor.HttpContextScopeImplementation.<>c__DisplayClass7.<.ctor>b__4() in d:\Projects\Orchard-Git\orchard\src\Orchard\Environment\WorkContextAccessor.cs:line 90
   at Orchard.Environment.WorkContextAccessor.HttpContextScopeImplementation.System.IDisposable.Dispose() in d:\Projects\Orchard-Git\orchard\src\Orchard\Environment\WorkContextAccessor.cs:line 95
   at Orchard.Mvc.Routes.ShellRoute.HttpAsyncHandler.EndProcessRequest(IAsyncResult result) in d:\Projects\Orchard-Git\orchard\src\Orchard\Mvc\Routes\ShellRoute.cs:line 162
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)
InnerException:

And more in log file:

2015-03-16 09:51:19,044 [11] Orchard.ContentManagement.DefaultContentManager - Default - GenericADOException thrown from IContentHandler by Orchard.Autoroute.Handlers.AutoroutePartHandler
NHibernate.Exceptions.GenericADOException: could not execute query
[ SELECT this_.Id as Id186_3_, this_.Number as Number186_3_, this_.Published as Published186_3_, this_.Latest as Latest186_3_, this_.Data as Data186_3_, this_.ContentItemRecord_id as ContentI6_186_3_, autoroutep1_.Id as Id222_0_, autoroutep1_.UseCustomPattern as UseCusto2_222_0_, autoroutep1_.CustomPattern as CustomPa3_222_0_, autoroutep1_.DisplayAlias as DisplayA4_222_0_, autoroutep1_.ContentItemRecord_id as ContentI5_222_0_, contentite4_.Id as Id185_1_, contentite4_.Data as Data185_1_, contentite4_.ContentType_id as ContentT3_185_1_, contenttyp5_.Id as Id187_2_, contenttyp5_.Name as Name187_2_ FROM Orchard_Framework_ContentItemVersionRecord this_ inner join Orchard_Autoroute_AutoroutePartRecord autoroutep1_ on this_.Id=autoroutep1_.Id left outer join Orchard_Framework_ContentItemRecord contentite4_ on this_.ContentItemRecord_id=contentite4_.Id left outer join Orchard_Framework_ContentTypeRecord contenttyp5_ on contentite4_.ContentType_id=contenttyp5_.Id WHERE (autoroutep1_.DisplayAlias is not null and autoroutep1_.DisplayAlias like @p0) and this_.Published = @p1 ]
Name:cp0 - Value:info/news/2015/03/news% Name:cp1 - Value:True
[SQL: SELECT this_.Id as Id186_3_, this_.Number as Number186_3_, this_.Published as Published186_3_, this_.Latest as Latest186_3_, this_.Data as Data186_3_, this_.ContentItemRecord_id as ContentI6_186_3_, autoroutep1_.Id as Id222_0_, autoroutep1_.UseCustomPattern as UseCusto2_222_0_, autoroutep1_.CustomPattern as CustomPa3_222_0_, autoroutep1_.DisplayAlias as DisplayA4_222_0_, autoroutep1_.ContentItemRecord_id as ContentI5_222_0_, contentite4_.Id as Id185_1_, contentite4_.Data as Data185_1_, contentite4_.ContentType_id as ContentT3_185_1_, contenttyp5_.Id as Id187_2_, contenttyp5_.Name as Name187_2_ FROM Orchard_Framework_ContentItemVersionRecord this_ inner join Orchard_Autoroute_AutoroutePartRecord autoroutep1_ on this_.Id=autoroutep1_.Id left outer join Orchard_Framework_ContentItemRecord contentite4_ on this_.ContentItemRecord_id=contentite4_.Id left outer join Orchard_Framework_ContentTypeRecord contenttyp5_ on contentite4_.ContentType_id=contenttyp5_.Id WHERE (autoroutep1_.DisplayAlias is not null and autoroutep1_.DisplayAlias like @p0) and this_.Published = @p1] ---> System.Data.SqlClient.SqlException: Transaction (Process ID 59) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)
at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more)
at System.Data.SqlClient.SqlDataReader.Read()
at NHibernate.Driver.NHybridDataReader.Read() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Driver\NHybridDataReader.cs:line 116
at NHibernate.AdoNet.ResultSetWrapper.Read() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\AdoNet\ResultSetWrapper.cs:line 47
at NHibernate.Loader.Loader.DoQuery(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Loader\Loader.cs:line 487
at NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Loader\Loader.cs:line 251
at NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Loader\Loader.cs:line 1564
--- End of inner exception stack trace ---
at NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Loader\Loader.cs:line 1581
at NHibernate.Loader.Loader.ListIgnoreQueryCache(ISessionImplementor session, QueryParameters queryParameters) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Loader\Loader.cs:line 1472
at NHibernate.Loader.Loader.List(ISessionImplementor session, QueryParameters queryParameters, ISet
1 querySpaces, IType[] resultTypes) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Loader\Loader.cs:line 1467
at NHibernate.Loader.Criteria.CriteriaLoader.List(ISessionImplementor session) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Loader\Criteria\CriteriaLoader.cs:line 76
at NHibernate.Impl.SessionImpl.List(CriteriaImpl criteria, IList results) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\SessionImpl.cs:line 1987
at NHibernate.Impl.CriteriaImpl.List(IList results) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\CriteriaImpl.cs:line 265
at NHibernate.Impl.CriteriaImpl.ListT in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\CriteriaImpl.cs:line 277
at Orchard.ContentManagement.DefaultContentQuery.Slice(Int32 skip, Int32 count) in d:\Projects\Orchard-Git\orchard\src\Orchard\ContentManagement\DefaultContentQuery.cs:line 161
at Orchard.ContentManagement.DefaultContentQuery.ContentQuery1.Orchard.ContentManagement.IContentQuery<T>.List() in d:\Projects\Orchard-Git\orchard\src\Orchard\ContentManagement\DefaultContentQuery.cs:line 262
at Orchard.Autoroute.Services.AutorouteService.GetSimilarPaths(String path)
at Orchard.Autoroute.Services.AutorouteService.ProcessPath(AutoroutePart part)
at Orchard.Autoroute.Handlers.AutoroutePartHandler.ProcessAlias(AutoroutePart part)
at Orchard.Autoroute.Handlers.AutoroutePartHandler.CreateAlias(AutoroutePart part)
at Orchard.Autoroute.Handlers.AutoroutePartHandler.<.ctor>b__0(UpdateContentContext ctx, AutoroutePart part)
at Orchard.ContentManagement.Handlers.ContentHandler.InlineStorageFilter
1.Updated(UpdateContentContext context, TPart instance) in d:\Projects\Orchard-Git\orchard\src\Orchard\ContentManagement\Handlers\ContentHandler.cs:line 152
at Orchard.ContentManagement.Handlers.StorageFilterBase1.Orchard.ContentManagement.Handlers.IContentStorageFilter.Updated(UpdateContentContext context) in d:\Projects\Orchard-Git\orchard\src\Orchard\ContentManagement\Handlers\StorageFilterBase.cs:line 67
at Orchard.ContentManagement.Handlers.ContentHandler.Orchard.ContentManagement.Handlers.IContentHandler.Updated(UpdateContentContext context) in d:\Projects\Orchard-Git\orchard\src\Orchard\ContentManagement\Handlers\ContentHandler.cs:line 264
at Orchard.ContentManagement.DefaultContentManager.<>c__DisplayClass7f.<UpdateEditor>b__7e(IContentHandler handler) in d:\Projects\Orchard-Git\orchard\src\Orchard\ContentManagement\DefaultContentManager.cs:line 646
at Orchard.InvokeExtensions.Invoke[TEvents](IEnumerable
1 events, Action`1 dispatch, ILogger logger) in d:\Projects\Orchard-Git\orchard\src\Orchard\InvokeExtensions.cs:line 17
2015-03-16 09:51:20,170 [11] NHibernate.Event.Default.AbstractFlushingEventListener - Default