umbraco / Umbraco-CMS

Umbraco is a free and open source .NET content management system helping you deliver delightful digital experiences.
https://umbraco.com
Other
4.49k stars 2.69k forks source link

Site crashes when editor submits a large number of pages for translation #4428

Closed ClientiWeb closed 5 years ago

ClientiWeb commented 5 years ago

We've experienced this bug on one of our Umbraco Cloud projects with many sites, pages & languages. The entire site crashes when a large number of pages is being send for translations.

Probably the same issue addressed in here: https://our.umbraco.com/forum/using-umbraco-and-getting-started/86811-azure-app-pool-max-100-crash-when-submitting-for-translations-v763 https://issues.umbraco.org/issue/U4-10471

Error message in log:

An unhandled exception occurred
System.Web.HttpUnhandledException (0x80004005): Exception of type 'System.Web.HttpUnhandledException' was thrown. ---> System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.<>c__DisplayClass20_0.<ExecuteAction>b__0()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func)
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction(Action action)
   at Umbraco.Core.Persistence.PetaPocoConnectionExtensions.OpenWithRetry(IDbConnection connection, RetryPolicy retryPolicy)
   at Umbraco.Core.Persistence.PetaPocoConnectionExtensions.OpenWithRetry(IDbConnection connection)
   at Umbraco.Core.Persistence.Database.OpenSharedConnection()
   at Umbraco.Core.Persistence.Database.BeginTransaction(IsolationLevel isolationLevel)
   at Umbraco.Core.Scoping.Scope.get_Database()
   at Umbraco.Core.Persistence.UnitOfWork.ScopeUnitOfWork.get_Database()
   at Umbraco.Core.Persistence.Repositories.TaskRepository.PersistNewItem(Task entity)
   at Umbraco.Core.Cache.NoRepositoryCachePolicy`2.Create(TEntity entity, Action`1 persistNew)
   at Umbraco.Core.Persistence.Repositories.RepositoryBase`2.PersistNewItem(IEntity entity)
   at Umbraco.Core.Persistence.UnitOfWork.ScopeUnitOfWork.Commit(Action`1 transactionCompleting)
   at Umbraco.Core.Persistence.UnitOfWork.ScopeUnitOfWork.Commit()
   at Umbraco.Core.Services.TaskService.Save(Task task)
   at umbraco.cms.businesslogic.task.Task.Save()
   at umbraco.cms.businesslogic.translation.Translation.MakeNew(CMSNode node, User user, User translator, Language language, String comment, Boolean includeSubpages, Boolean sendEmail)
   at umbraco.cms.businesslogic.translation.Translation.MakeNew(CMSNode node, User user, User translator, Language language, String comment, Boolean includeSubpages, Boolean sendEmail)
   at umbraco.cms.businesslogic.translation.Translation.MakeNew(CMSNode node, User user, User translator, Language language, String comment, Boolean includeSubpages, Boolean sendEmail)
   at umbraco.cms.businesslogic.translation.Translation.MakeNew(CMSNode node, User user, User translator, Language language, String comment, Boolean includeSubpages, Boolean sendEmail)
   at umbraco.cms.businesslogic.translation.Translation.MakeNew(CMSNode node, User user, User translator, Language language, String comment, Boolean includeSubpages, Boolean sendEmail)
   at umbraco.presentation.dialogs.sendToTranslation.doTranslation_Click(Object sender, EventArgs e)
   at System.Web.UI.WebControls.Button.OnClick(EventArgs e)
   at System.Web.UI.WebControls.Button.RaisePostBackEvent(String eventArgument)
   at System.Web.UI.WebControls.Button.System.Web.UI.IPostBackEventHandler.RaisePostBackEvent(String eventArgument)
   at System.Web.UI.Page.RaisePostBackEvent(IPostBackEventHandler sourceControl, String eventArgument)
   at System.Web.UI.Page.RaisePostBackEvent(NameValueCollection postData)
   at System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)
   at System.Web.UI.Page.HandleError(Exception e)
   at System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)
   at System.Web.UI.Page.ProcessRequest(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)
   at System.Web.UI.Page.ProcessRequest()
   at System.Web.UI.Page.ProcessRequestWithNoAssert(HttpContext context)
   at System.Web.UI.Page.ProcessRequest(HttpContext context)
   at ASP.umbraco_dialogs_sendtotranslation_aspx.ProcessRequest(HttpContext context) in c:\local\Temporary ASP.NET Files\root\96504987\8d93f408\App_Web_sendtotranslation.aspx.10695ae8.d5kyuxed.0.cs:line 0
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)
nul800sebastiaan commented 5 years ago

Hey there @ClientiWeb, if you look in that stack trace you'll see this is coming from the 301 URL tracker plugin you've got installed and not from Umbraco itself. I'd recommend reporting an issue with them instead.

ClientiWeb commented 5 years ago

@nul800sebastiaan Wrong stack trace. I added the correct one, which was the first one to appear in the trace log. The original stack trace didn't appear until later, when max pool size was already reached. Can you reopen?

nul800sebastiaan commented 5 years ago

Thanks! Looks like this was narrowed down to the Log.Add calls. It's probably a good idea to update this to use AuditService.Add instead, as per the code for Log.Add:

image

I've marked this as "Up for grabs" so that you or someone else coming along could create a pull request for it.

OlePc commented 5 years ago

Some additional trace logs from the same second as the OP one happened:

Error executing query insert into umbracoLog (userId, nodeId, logHeader, logComment) values (@userId, @nodeId, @logHeader, @comment)
System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.<>c__DisplayClass20_0.<ExecuteAction>b__0()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func)
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction(Action action)
   at Umbraco.Core.Persistence.PetaPocoConnectionExtensions.OpenWithRetry(IDbConnection connection, RetryPolicy retryPolicy)
   at Umbraco.Core.Persistence.PetaPocoConnectionExtensions.OpenWithRetry(IDbConnection connection)
   at Umbraco.Core.Persistence.Database.OpenSharedConnection()
   --- End of inner exception stack trace ---
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor)
   at System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object[] parameters, Object[] arguments)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at umbraco.DataLayer.CurrentConnectionUsing..ctor()
   at umbraco.DataLayer.SqlHelpers.SqlServer.SqlServerHelper.ExecuteNonQuery(String commandText, SqlParameter[] parameters)
   at umbraco.DataLayer.SqlHelper`1.ExecuteNonQuery(String commandText, IParameter[] parameters)
Error executing query SELECT id, createDate, trashed, parentId, nodeObjectType, nodeUser, level, path, sortOrder, uniqueID, text FROM umbracoNode WHERE ParentID = @ParentID AND nodeObjectType = @type order by sortOrder
System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.<>c__DisplayClass20_0.<ExecuteAction>b__0()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func)
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction(Action action)
   at Umbraco.Core.Persistence.PetaPocoConnectionExtensions.OpenWithRetry(IDbConnection connection, RetryPolicy retryPolicy)
   at Umbraco.Core.Persistence.PetaPocoConnectionExtensions.OpenWithRetry(IDbConnection connection)
   at Umbraco.Core.Persistence.Database.OpenSharedConnection()
   --- End of inner exception stack trace ---
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor)
   at System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object[] parameters, Object[] arguments)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at umbraco.DataLayer.CurrentConnectionUsing..ctor()
   at umbraco.DataLayer.SqlHelpers.SqlServer.SqlServerHelper.ExecuteReader(String commandText, SqlParameter[] parameters)
   at umbraco.DataLayer.SqlHelper`1.ExecuteReader(String commandText, IParameter[] parameters)
nul800sebastiaan commented 5 years ago

Please note that in 7.5.5 the usage of sqlHelper was wrapped in a using block so it could be Disposed after use, I don't know which version you're currently on, so an upgrade might be worth it if you're on an older version.

Related commit: https://github.com/umbraco/Umbraco-CMS/commit/ee3a4614#diff-ebac7d67ee16acb4df0bb2c86b943529R169

OlePc commented 5 years ago

@nul800sebastiaan The site is currently running 7.12.4. The site was recently migrated to Umbraco Cloud, and was previously upgraded manually to 7.12.4. So the using block you're talking of should be present.

nul800sebastiaan commented 5 years ago

The using can't be missing, else you're not running 7.12.4! ;-)

Anyway, it's up-for-grabs, if you'd like to test out if it helps to replace the Log.Add call then be our guest and send a PR our way.

nul800sebastiaan commented 5 years ago

Fixed in https://github.com/umbraco/Umbraco-CMS/pull/4738