AbleCommerce Shopping Cart Software

I just upgraded from 7.0.3 to AC Gold R6. My install seems to be running very slow on my Windows 2008 R2 Server with the latest Microsoft patches. Occasionally when I click on a category page, I am presented with an error page and the following in my stack dump in log file:


2013-11-20 11:58:49,645 WARN ADOExceptionReporter System.Data.SqlClient.SqlException (0x80131904): Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.SqlInternalConnection.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)
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 System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
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)
ClientConnectionId:5535776d-3c2f-4d43-99f0-21406af05ece
2013-11-20 11:58:49,645 ERROR ADOExceptionReporter Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
2013-11-20 11:58:49,645 WARN ADOExceptionReporter System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
2013-11-20 11:58:49,645 ERROR ADOExceptionReporter The wait operation timed out
2013-11-20 11:58:49,645 ERROR AbleCommerce Error in user maintenance
NHibernate.Exceptions.GenericADOException: could not execute query
[ SELECT DISTINCT UserId FROM ac_Users WHERE UserId NOT IN (SELECT DISTINCT U.UserId FROM ac_Users U LEFT JOIN ac_UserGroups UG ON U.UserId = UG.UserId WHERE (UG.GroupId = 31 OR (UG.UserId IS NOT NULL AND UG.SubscriptionId IS NULL))) AND IsAnonymous = 0 ]
[SQL: SELECT DISTINCT UserId FROM ac_Users WHERE UserId NOT IN (SELECT DISTINCT U.UserId FROM ac_Users U LEFT JOIN ac_UserGroups UG ON U.UserId = UG.UserId WHERE (UG.GroupId = 31 OR (UG.UserId IS NOT NULL AND UG.SubscriptionId IS NULL))) AND IsAnonymous = 0] ---> 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.SqlInternalConnection.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)
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 System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
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)
--- End of inner exception stack trace ---
at NHibernate.Loader.Loader.DoList(ISessionImplementor session, QueryParameters queryParameters)
at NHibernate.Loader.Loader.ListIgnoreQueryCache(ISessionImplementor session, QueryParameters queryParameters)
at NHibernate.Loader.Loader.List(ISessionImplementor session, QueryParameters queryParameters, ISet`1 querySpaces, IType[] resultTypes)
at NHibernate.Impl.SessionImpl.ListCustomQuery(ICustomQuery customQuery, QueryParameters queryParameters, IList results)
at NHibernate.Impl.SessionImpl.List(NativeSQLQuerySpecification spec, QueryParameters queryParameters, IList results)
at NHibernate.Impl.SessionImpl.List(NativeSQLQuerySpecification spec, QueryParameters queryParameters)
at NHibernate.Impl.SqlQueryImpl.List()
at CommerceBuilder.Services.MaintenanceWorker.MaintainUsers(Int32 anonymousUserLifespan, Int32 anonymousAffiliateUserLifespan, Boolean includeInactive)
at CommerceBuilder.Services.MaintenanceWorker.MaintainUsers()
at CommerceBuilder.Services.MaintenanceWorker.RunMaintenance()
2013-11-20 11:59:21,423 ERROR oNet.AbstractBatcher Could not execute query: SELECT DISTINCT UserId FROM ac_Users WHERE UserId NOT IN (SELECT DISTINCT U.UserId FROM ac_Users U LEFT JOIN ac_UserGroups UG ON U.UserId = UG.UserId WHERE (UG.GroupId = 31 OR (UG.UserId IS NOT NULL AND UG.SubscriptionId IS NULL))) AND IsAnonymous = 0
System.Data.SqlClient.SqlException (0x80131904): Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.SqlInternalConnection.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)
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 System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
ClientConnectionId:5535776d-3c2f-4d43-99f0-21406af05ece

I tried to execute the following statement from the log and it takes a very long time to complete on AC Gold R6 database, but runs reasonably fast on 7.0.3 database:

SELECT DISTINCT UserId FROM ac_Users WHERE UserId NOT IN (SELECT DISTINCT U.UserId FROM ac_Users U LEFT JOIN ac_UserGroups UG ON U.UserId = UG.UserId WHERE (UG.GroupId = 31 OR (UG.UserId IS NOT NULL AND UG.SubscriptionId IS NULL))) AND IsAnonymous = 0


There's at least 1195801 records in ac_Users. AC Gold R6 takes 7 seconds while 7.0.3 only takes 2. Any help? Thanks in advance.

OK. I solved my own problem and perhaps save others from the pain. The reason for the poor performance was due to the aforementioned query. We never upgraded past 7.0.3 and there was no number of days specified for anonymous users. Over a long period of time, the anonymous users piled up really slowing down the queries. It would be nice if AC Gold put some logic to handle this rare condition.

You can't upgrade from 7.0.3 to Gold directly. Also, it is mentioned in the upgrade doc that you should make sure that anonymous users and web activity logs are cleaned up prior to upgrading.

http://help.ablecommerce.com/upgrades/a ... o_gold.htm

There are reasons we don't do the maintenance cleanup during the upgrade process. If you review the maintenance document linked from the upgrade document, you might understand why. I've seen databases with over a million records that needed purged, and the best way to accomplish the task was with a manual SQL query. If you had been upgrading from 7.0.7, then you would find that the database maintenance was probably working fine.

Sorry, but I didn't make myself clear in this post which is detailed in another post. What I mean is that we're going to R6 from 7.0.3 and not that we're going directly to R6 without going through the intermediate versions. We went through the upgrade process as recommended. I did try to run the anonymous maintenance patch on 7.0.3 (documentation said it would work on 7.0.6 and under) and received the error "'CommerceBuilder.Search.KeywordSearchHelper' does not contain a definition for 'RebuildCatalog'". I ignored the error and continued, figuring the database didn't need a maintenance since version 7.0.7 worked.

The upgrade process from 7.0.3 to 7.0.7 went smoothly, but the R6 upgrade is when this particular issue as well as the database upgrade issue viewtopic.php?f=65&t=17612) surfaced.

Regardless, I went through 7.0.7 and it d