Speed discrepancy calling same script from DBMS vs DataAcces

2 posts, 0 answers
  1. Aleksandar
    Aleksandar avatar
    2 posts
    Member since:
    Jun 2011

    Posted 02 Jul 2015 Link to this post

    Hello Telerik,

    We ran into an issue with DataAccess being very slow (throwing timeout exception - slow) when running from code, but same script ran from DBMS ran much faster.

     I know there is not much you can do, but I am fishing for some ideas how to get to the bottom of the issue and solution for it.

    Details:

    When accessing data from application using DataAccess ORM we get Timeout exception (at the end of this post). But when I intercept the SQL script generated by DataAccess in profiler and execute it in DBMS it executes in 2 seconds.

    View has a lot of rows (in excess of 20 million).

    Return set is only cca 30 rows.

    Indexes are set on all relevant columns.

    Level2Cache is enabled but not for this view.

    Any ideas how to get to the bottom of this issue would be greatly appreciated.

     

    ​Exception:

    Telerik.OpenAccess.Exceptions.DataStoreException: Error executing query: Telerik.OpenAccess.RT.sql.SQLException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception: The wait operation timed out
       --- End of inner exception stack trace ---
       at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 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.TryConsumeMetaData()
       at System.Data.SqlClient.SqlDataReader.get_MetaData()
       at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
       at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds)
       at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 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 OpenAccessRuntime.CommandWrapper.ExecuteReader(CommandBehavior behavior)
       at Telerik.OpenAccess.Runtime.Logging.LoggingDbCommand.ExecuteDbDataReader(CommandBehavior behavior)
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.CommandImp.ExecuteReader()
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.PreparedStatementImp.executeQuery(Nullable`1 commandTimeout)
       --- End of inner exception stack trace ---
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.PreparedStatementImp.executeQuery(Nullable`1 commandTimeout)
       at OpenAccessRuntime.Relational.conn.PooledPreparedStatement.executeQuery(Nullable`1 commandTimeout)
       at OpenAccessRuntime.Relational.fetch.FetchResultImp.Execute()
    SQL:
    SELECT CONVERT(DATE, a.[From]) AS  EXPR1, DATEPART(hour,a.[From]) AS  EXPR2, a.[Name] AS COL3, a.[ZoneId] AS COL4, SUM(a.[Value]) AS  EXPR5, MIN(a.[From]) AS  EXPR6, MAX(a.[To]) AS  EXPR7 FROM [vTransit] a WHERE (a.[ZoneId] IN (?,?,?)) AND a.[Username] = ?                                       AND a.[From] >= ? AND a.[To] <= ? AND ((DATEPART(hour,a.[From]) = ?                                       AND DATEPART(minute,a.[From]) >= ? OR DATEPART(hour,a.[From]) > ?)) AND ((DATEPART(hour,a.[From]) = ?                                       AND DATEPART(minute,a.[From]) < ? OR DATEPART(hour,a.[From]) < ?)) GROUP BY CONVERT(DATE, a.[From]), DATEPART(hour,a.[From]), a.[Name], a.[ZoneId]  Telerik.OpenAccess.RT.sql.SQLException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception: The wait operation timed out
       --- End of inner exception stack trace ---
       at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 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.TryConsumeMetaData()
       at System.Data.SqlClient.SqlDataReader.get_MetaData()
       at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
       at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds)
       at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 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 OpenAccessRuntime.CommandWrapper.ExecuteReader(CommandBehavior behavior)
       at Telerik.OpenAccess.Runtime.Logging.LoggingDbCommand.ExecuteDbDataReader(CommandBehavior behavior)
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.CommandImp.ExecuteReader()
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.PreparedStatementImp.executeQuery(Nullable`1 commandTimeout)
       --- End of inner exception stack trace ---
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.PreparedStatementImp.executeQuery(Nullable`1 commandTimeout)
       at OpenAccessRuntime.Relational.conn.PooledPreparedStatement.executeQuery(Nullable`1 commandTimeout)
       at OpenAccessRuntime.Relational.fetch.FetchResultImp.Execute() ---> Telerik.OpenAccess.RT.sql.SQLException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception: The wait operation timed out
       --- End of inner exception stack trace ---
       at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 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.TryConsumeMetaData()
       at System.Data.SqlClient.SqlDataReader.get_MetaData()
       at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
       at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds)
       at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 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 OpenAccessRuntime.CommandWrapper.ExecuteReader(CommandBehavior behavior)
       at Telerik.OpenAccess.Runtime.Logging.LoggingDbCommand.ExecuteDbDataReader(CommandBehavior behavior)
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.CommandImp.ExecuteReader()
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.PreparedStatementImp.executeQuery(Nullable`1 commandTimeout)
       --- End of inner exception stack trace ---
       at Telerik.OpenAccess.RT.Adonet2Generic.Impl.PreparedStatementImp.executeQuery(Nullable`1 commandTimeout)
       at OpenAccessRuntime.Relational.conn.PooledPreparedStatement.executeQuery(Nullable`1 commandTimeout)
       at OpenAccessRuntime.Relational.fetch.FetchResultImp.Execute()
       --- End of inner exception stack trace ---
       at OpenAccessRuntime.ExceptionWrapper.Throw()
       at OpenAccessRuntime.storagemanager.logging.LoggingStorageManager.fetchNextQueryResult(ApplicationContext context, RunningQuery runningQuery, Int32 skipAmount)
       at OpenAccessRuntime.DataObjects.ForwardQueryResult.Initialize()
       at OpenAccessRuntime.DataObjects.ForwardQueryResult.get_Item(Int32 indexParam)
       at OpenAccessRuntime.ListEnumerator.setCurrent(Int32 _pos)
       at OpenAccessRuntime.ListEnumerator.Move(Int32 relative)
       at Telerik.OpenAccess.Query.TypedEnumerator`1.MoveNext()
       at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
       at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
       at Controller.CounterValueController.GetTransitsForZonesP(IEnumerable`1 zoneIds, DateTime dateFrom, DateTime dateTo, TimeResolution timeResolution, Nullable`1 workHoursFrom, Nullable`1 workHoursTo, String appUserName)
       at Controller.WebApiPCManager.TransitsGetForZones(IEnumerable`1 zoneIds, DateTime dateFrom, DateTime dateTo, TimeResolution timeResolution, TimeSpan workHoursFrom, TimeSpan workHoursTo, String appUserName)
       at WebApiService.Controllers.ZoneTransitController.Get(String zoneIdCollection, String dateFrom, String dateTo, Int32 timeResolution, String workHoursFrom, String workHoursTo)

  2. Thomas
    Admin
    Thomas avatar
    590 posts

    Posted 03 Jul 2015 Link to this post

    Hello Alexandar,

    when there is such a large discrepancy and not much data involved from the result set, the query execution must be different. My gut feeling is, that there is a NVARCHAR/VARCHAR issue in this, 
    because that is where I had seen huge differences in other projects.
    Can you check that the defined index is used? Also, please check the UserName property: It must match
    the column definition wrt. this: the converter used must be the right one. NVARCHAR=StringVariableLength converter, VARCHAR=AnsiStringVariableLength.

    Regards,
    Thomas
    Telerik
     
    Check out the latest announcement about Telerik Data Access vNext as a powerful framework able to solve core development problems.
  3. DevCraft banner
Back to Top