NHibernate - "GenericADOException: could not execute query"

2
votes

Our production environment that uses NHibernate v3.1.0.4000 suddenly started giving this error when searching with full-text search:

[SqlException (0x80131904): Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.] System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) +404 System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning() +412 System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) +1363 System.Data.SqlClient.SqlDataReader.ConsumeMetaData() +59 System.Data.SqlClient.SqlDataReader.get_MetaData() +118 System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) +6388257 System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async) +6389826 System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) +538 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 NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd) +845 NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session) +580 NHibernate.Loader.Loader.DoQuery(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies) +275 NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies) +205 NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters) +195

[GenericADOException: could not execute query [ SELECT count(distinct this_.IdDocument) as y0_ FROM Document.Document this_ inner join Document.DocumentCopy documentc1_ on this_.IdDocument=documentc1_.IdDocument WHERE ((@p0 = @p1 and contains(this_.Title, @p2)) and this_.IsDeleted = @p3) and (((@p4 = @p5 and documentc1_.CreationDate >= @p6) and documentc1_.CreationDate <= @p7) and (documentc1_.IdOwnedByGroup = @p8 or documentc1_.IdCreatedByGroup = @p9)) ] Positional parameters: #0>0 #1>0 #2>"ýÿýÿýÿýÿýÿýÿýÿýÿ*" #3>False #4>0 #5>0 #6>12/5/2015 12:00:00 ýÿýÿ #7>12/5/2016 11:59:00 ýÿýÿ #8>1 #9>1 [SQL: SELECT count(distinct this_.IdDocument) as y0_ FROM Document.Document this_ inner join Document.DocumentCopy documentc1_ on this_.IdDocument=documentc1_.IdDocument WHERE ((@p0 = @p1 and contains(this_.Title, @p2)) and this_.IsDeleted = @p3) and (((@p4 = @p5 and documentc1_.CreationDate >= @p6) and documentc1_.CreationDate <= @p7) and (documentc1_.IdOwnedByGroup = @p8 or documentc1_.IdCreatedByGroup = @p9))]] NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters) +637 NHibernate.Loader.Loader.ListIgnoreQueryCache(ISessionImplementor session, QueryParameters queryParameters) +23 NHibernate.Loader.Criteria.CriteriaLoader.List(ISessionImplementor session) +60 NHibernate.Impl.SessionImpl.List(CriteriaImpl criteria, IList results) +1025 NHibernate.Impl.CriteriaImpl.List(IList results) +63 NHibernate.Impl.CriteriaImpl.UniqueResult() +57 Domain.Repositories.DocumentRepository.Domain.Abstract.IDocumentRepository.GetAll(Criteria1 criteria, Int32& count, Dictionary2 openFieldCriteria) +272 ServicesImplementation.DocumentService.GetDocuments(Criteria1 criteria, Int32& count, String metadataSearchTerm) +510 Docman.Models.List.ListModel.GetDocuments(Int32& count) +102 ASP._Page_Views_List_Index_cshtml.Execute() in d:\wwwroot\inetpub\docman\Views\List\Index.cshtml:27 System.Web.WebPages.WebPageBase.ExecutePageHierarchy() +280 System.Web.Mvc.WebViewPage.ExecutePageHierarchy() +104 System.Web.WebPages.StartPage.ExecutePageHierarchy() +143 System.Web.WebPages.WebPageBase.ExecutePageHierarchy(WebPageContext pageContext, TextWriter writer, WebPageRenderingBase startPage) +157 System.Web.Mvc.ViewResultBase.ExecuteResult(ControllerContext context) +384 System.Web.Mvc.<>c__DisplayClass1c.<InvokeActionResultWithFilters>b__19() +33 System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(IResultFilter filter, ResultExecutingContext preContext, Func1 continuation) +826372 System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters(ControllerContext controllerContext, IList`1 filters, ActionResult actionResult) +265 System.Web.Mvc.ControllerActionInvoker.InvokeAction(ControllerContext controllerContext, String actionName) +827248 System.Web.Mvc.Controller.ExecuteCore() +159 System.Web.Mvc.ControllerBase.Execute(RequestContext requestContext) +335 System.Web.Mvc.<>c__DisplayClassb.b__5() +62 System.Web.Mvc.Async.<>c__DisplayClass1.b__0() +20 System.Web.Mvc.<>c__DisplayClasse.b__d() +54 System.Web.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() +469 System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously) +375

I have tried the above listed query on SSMS and it seemed running fine and fast.

A similar error is mentioned here: Nhibernate FieldNameLookup throws IndexOutOfRangeException, although my error message does not contain any IndexOutOfRangeException in it.

Can anyone tell me what could be the cause of this?

UPDATE:

More info :

We are using projections.

According to the error log, the error originates from some query that only returns a count and not many rows with many fields.

As I have said before, the same query (listed in the error log) runs fast and with no issues when I run it from SSMS. Yet, all queries made from the app that execute this SQL query seem to fail with the above error.

The code might not be clear to you since we use a custom wrapper for NH.

I think I am wrong on the order of exceptions and first the timeout happens and then the ADO.net reports the other error. So, I guess it is a timeout after all...

UPDATE 2:

After some extra research, it seems this is related to this issue and the query is indeed timing out, just not from SSMS:

Query times out when executed from web, but super-fast when executed from SSMS

1
c#.netasp.net-mvcnhibernatefluent-nhibernate
The datails says is Timeout issue. – Najera
how much data are you bringing back? what does the code that is doing this look like? are you using projections? – Fran
@Najera If you look below that 1st exception, there is another exception that seems to be the inner exception. – user2173353
@Najera But maybe you are right: first it must be the SQL exception and then the ADO one. :^) I wish people just wrote Inner exception :\r\n in their exception logging. It would make things much more obvious... – user2173353
@Fran I have added some more details. I am thinking now that MAYBE this indeed is a timeout issue. I am a bit confused with the order of the two exceptions... – user2173353

1 Answers

-1
votes

That turned out to be a timeout which could not be reproduced from SSMS because there it was using a different value for ARITHABORT (between my app session and the SSMS session).

Once I had set the default value for it to ON/1 for the DB, everything was fixed:

USE [master];
GO
ALTER DATABASE [{database_name}] SET ARITHABORT ON WITH NO_WAIT;
GO

See here: https://dba.stackexchange.com/a/95090/71232