U4-1479 - SQL Race condition with 2 MNTP editors with same start node on document

Created by Randy McCluer 15 Jan 2013, 16:02:46 Updated by Morten Christensen 18 Jan 2013, 21:05:02

Relates to: U4-1389

Only one of the trees populates correctly, the tree asmx for the other will 500. When debugging that, you find the trace below.

I'm guessing this is also possible in other scenarios, but this is the first one I've run into.

"There is already an open DataReader associated with this Command which must be closed first." at System.Data.SqlClient.SqlInternalConnectionTds.ValidateConnectionForExecute(SqlCommand command) at System.Data.SqlClient.SqlCommand.ValidateCommand(String method, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method) at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior) at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader() at Umbraco.Core.Persistence.Database.<Query>d__1c1.MoveNext() in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Core\Persistence\PetaPoco.cs:line 1122 at System.Collections.Generic.List1..ctor(IEnumerable1 collection) at System.Linq.Enumerable.ToList[TSource](IEnumerable1 source) at Umbraco.Core.Persistence.Database.Fetch[T1,T2](Sql sql) in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Core\Persistence\PetaPoco.cs:line 827 at Umbraco.Core.Persistence.Repositories.TemplateRepository.PerformGet(Int32 id) in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Core\Persistence\Repositories\TemplateRepository.cs:line 58 at Umbraco.Core.Persistence.Repositories.RepositoryBase2.Get(TId id) in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Core\Persistence\Repositories\RepositoryBase.cs:line 95 at Umbraco.Core.Persistence.Repositories.ContentTypeRepository.b__0(DocumentTypeDto template) in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Core\Persistence\Repositories\ContentTypeRepository.cs:line 55 at System.Linq.Enumerable.WhereSelectListIterator2.MoveNext() at System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable1 source, Func2 predicate) at Umbraco.Core.Models.ContentType.get_DefaultTemplate() in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Core\Models\ContentType.cs:line 38 at Umbraco.Core.Models.Content.get_Template() in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Core\Models\Content.cs:line 83 at umbraco.cms.businesslogic.web.Document.SetupNode(IContent content) in k:\code\Umbraco\umbraco source\60changes\src\umbraco.cms\businesslogic\web\Document.cs:line 1362 at umbraco.cms.businesslogic.web.Document..ctor(IContent content) in k:\code\Umbraco\umbraco source\60changes\src\umbraco.cms\businesslogic\web\Document.cs:line 106 at umbraco.cms.businesslogic.web.Document.<GetChildrenForTree>b__6(IContent x) in k:\code\Umbraco\umbraco source\60changes\src\umbraco.cms\businesslogic\web\Document.cs:line 442 at System.Linq.Enumerable.WhereSelectEnumerableIterator2.MoveNext() at System.Linq.Buffer1..ctor(IEnumerable1 source) at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source) at umbraco.cms.businesslogic.web.Document.GetChildrenForTree(Int32 NodeId) in k:\code\Umbraco\umbraco source\60changes\src\umbraco.cms\businesslogic\web\Document.cs:line 443 at umbraco.cms.presentation.Trees.BaseContentTree.Render(XmlTree& Tree) in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Web\umbraco.presentation\umbraco\Trees\BaseContentTree.cs:line 160 at umbraco.presentation.webservices.TreeDataService.LoadTree(TreeRequestParams treeParams) in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Web\umbraco.presentation\umbraco\webservices\TreeDataService.ashx.cs:line 96 at umbraco.presentation.webservices.TreeDataService.GetXmlTree() in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Web\umbraco.presentation\umbraco\webservices\TreeDataService.ashx.cs:line 57 at umbraco.presentation.webservices.TreeDataService.ProcessRequest(HttpContext context) in k:\code\Umbraco\umbraco source\60changes\src\Umbraco.Web\umbraco.presentation\umbraco\webservices\TreeDataService.ashx.cs:line 24

Comments

Morten Christensen 15 Jan 2013, 16:09:56

Which build is this? Or are you just running off latest source?


Randy McCluer 15 Jan 2013, 16:19:57

Running off of 94178194247a. I will get latest again and test. And sorry, I forgot a detail in my hurry. In the UI all you see is that only one of the trees loads. The stack I copied is what you find when you debug. Will updated ticket accordingly.


Randy McCluer 15 Jan 2013, 16:47:22

Confirmed against 7750a5946fd3 as well. Going to try to repro against blank 6.0 Beta install.


Randy McCluer 15 Jan 2013, 17:09:06

More test case info. Seems to work fine with root content node selected, but breaks on nodes lower in the tree. Can't test against v6 Beta because of #U4-1466.


Morten Christensen 15 Jan 2013, 17:25:47

I wonder if there is a different having selected a content node with or without a template? Have you tried this by any chance?


Randy McCluer 15 Jan 2013, 17:28:37

All of the nodes in my site have templates, so no, I haven't tried that. Let me install one of the StarterKits in my build to test a bit more. Do you have a preference of which one I should use?


Morten Christensen 15 Jan 2013, 17:45:23

No, don't think it matters which starterkit you use. But at first glance I think the template matters. As I recall, PetaPoco can have 3 open connections, so if the ContentRepository uses one, ContentTypeRepository opens one and if template exists that is fetched from the TemplateRepository, which also uses a connection. Now if one or all of those connections aren't closed properly then we have a problem. I'm not 100% sure this is the case, but worth investigating.


Randy McCluer 15 Jan 2013, 18:01:07

Easy repro steps. -Install SimpleStarterKit. -Create new MNTP datatype using homepage as start node. -Add 2 properties to Homepage DocType with that datatype.

When you go to edit the Homepage, you'll see "random" behavior in the MNTP trees on each page load. Sometimes one will load, sometimes neither. Loading the editor too many times rapidly also broke the entire admin, yielding "Handle is not valid" exception that required IISReset.


Stéphane Bouchard-Pagé 16 Jan 2013, 19:02:25

I got the same issue.

Just add 2 (Or more) MNTP on a document. That's it.

Url: /umbraco/webservices/TreeDataService.ashx?rnd=5c1bd76df12f4a2888aa677f533bc8cf&id=1047&treeType=FilteredContentTree&contextMenu=false&isDialog=true&dialogMode=id&nodeKey=1084&rnd2=30.7

Error 500

Stack Trace:

[InvalidOperationException: There is already an open DataReader associated with this Command which must be closed first.] System.Data.SqlClient.SqlInternalConnectionTds.ValidateConnectionForExecute(SqlCommand command) +6350339 System.Data.SqlClient.SqlCommand.ValidateCommand(String method, Boolean async) +271 System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) +138 System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) +28 System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method) +256 System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior) +19 System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader() +23 Umbraco.Core.Persistence.<Query>d__1c1.MoveNext() +1074 System.Collections.Generic.List1..ctor(IEnumerable1 collection) +472 System.Linq.Enumerable.ToList(IEnumerable1 source) +80 Umbraco.Core.Persistence.Repositories.TemplateRepository.PerformGet(Int32 id) +206 Umbraco.Core.Persistence.Repositories.RepositoryBase2.Get(TId id) +230 Umbraco.Core.Persistence.Repositories.ContentTypeRepository.&lt;PerformGet&gt;b__0(DocumentTypeDto template) +27 System.Linq.WhereSelectListIterator2.MoveNext() +232 System.Linq.Enumerable.FirstOrDefault(IEnumerable1 source, Func2 predicate) +200 umbraco.cms.businesslogic.web.Document.SetupNode(IContent content) +575 umbraco.cms.businesslogic.web.Document.<GetChildrenForTree>b__6(IContent x) +56 System.Linq.WhereSelectEnumerableIterator2.MoveNext() +238 System.Linq.Buffer1..ctor(IEnumerable1 source) +488 System.Linq.Enumerable.ToArray(IEnumerable1 source) +104 umbraco.cms.presentation.Trees.BaseContentTree.Render(XmlTree& Tree) +37 umbraco.presentation.webservices.TreeDataService.GetXmlTree() +136 umbraco.presentation.webservices.TreeDataService.ProcessRequest(HttpContext context) +86 System.Web.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() +625 System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously) +270

Thanks a lot!


Morten Christensen 18 Jan 2013, 10:10:57

Okay, so I believe I found the cause of this, which was actually due to a piece of code trying to fetch something from the database after the connection was closed.

I did some more research on when this issue would occur, and it only seemed to happen when the content containing the Multi-Node Tree Picker has a list of Allowed Templates. I isolated this as the offending code in the ContentTypeRepository:

contentType.AllowedTemplates = templates.Select(template => _templateRepository.Get(template.TemplateNodeId)); And because the AllowedTemplates is an IEnumerable the list wouldn't be executed until the DefaultTemplate is used on the content item in the backoffice. This basically means that the selection in the code above would be done after the connection to the database is closed/disposed and thus resulting in an exception.


Randy McCluer 18 Jan 2013, 20:29:29

Looks like it works fine now. Great job & glad it wasn't something more nefarious.


Morten Christensen 18 Jan 2013, 21:05:02

Yea me too .. You scared me with the "race condition" bit ;O)


Priority: Major

Type: Bug

State: Fixed

Assignee: Morten Christensen

Difficulty: Normal

Category: Architecture

Backwards Compatible: True

Fix Submitted:

Affected versions: 6.0.0

Due in version: 6.0.0

Sprint:

Story Points:

Cycle: