Open Closed

Log exceptions and Azure App Service 100% CPU #8972


0
ricavir created

Hi,

I'm running on Azure App Service with asp.net zero ASP.NET CORE 3.1 and Abp 5.5.

My app has been updated to ASP.NET CORE 3.1 4/5 weeks ago.

I've noticed a lot of exceptions on log file ; from my understanding of previous questions/issues they should not impact the app... but, I noticed that I'm having big CPU charges on azure 2 or 3 times per day. I can send you log file by mail if needed.

Here is some of them :

ERROR 2020-05-05 14:31:23,311 [25   ] .AspNetCore.SignalR.HubConnectionHandler - Error when dispatching 'OnDisconnectedAsync' on hub.
System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'Scope was already disposed. This is most likely a bug in the calling code.'.
   at Castle.MicroKernel.Lifestyle.ScopedLifestyleManager.GetScope(CreationContext context)
   at Castle.MicroKernel.Lifestyle.ScopedLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.Windsor.MsDependencyInjection.MsScopedLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.MicroKernel.Handlers.DefaultHandler.ResolveCore(CreationContext context, Boolean requiresDecommission, Boolean instanceRequired, Burden& burden)
   at Castle.MicroKernel.Handlers.DefaultHandler.Resolve(CreationContext context, Boolean instanceRequired)
   at Castle.MicroKernel.Handlers.AbstractHandler.Resolve(CreationContext context)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernelByType(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernel(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveCore(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.Resolve(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.CreateConstructorArguments(ConstructorCandidate constructor, CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.Instantiate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.InternalCreate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.AbstractComponentActivator.Create(CreationContext context, Burden burden)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.CreateInstance(CreationContext context, Boolean trackedExternally)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.MicroKernel.Handlers.DefaultHandler.ResolveCore(CreationContext context, Boolean requiresDecommission, Boolean instanceRequired, Burden& burden)
   at Castle.MicroKernel.Handlers.DefaultHandler.Resolve(CreationContext context, Boolean instanceRequired)
   at Castle.MicroKernel.Handlers.AbstractHandler.Resolve(CreationContext context)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernelByType(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernel(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveCore(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.Resolve(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.CreateConstructorArguments(ConstructorCandidate constructor, CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.Instantiate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.InternalCreate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.AbstractComponentActivator.Create(CreationContext context, Burden burden)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.CreateInstance(CreationContext context, Boolean trackedExternally)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.MicroKernel.Handlers.DefaultHandler.ResolveCore(CreationContext context, Boolean requiresDecommission, Boolean instanceRequired, Burden& burden)
   at Castle.MicroKernel.Handlers.DefaultHandler.Resolve(CreationContext context, Boolean instanceRequired)
   at Castle.MicroKernel.Handlers.AbstractHandler.Resolve(CreationContext context)
   at Castle.MicroKernel.DefaultKernel.ResolveComponent(IHandler handler, Type service, Arguments additionalArguments, IReleasePolicy policy, Boolean ignoreParentContext)
   at Castle.MicroKernel.DefaultKernel.Castle.MicroKernel.IKernelInternal.Resolve(Type service, Arguments arguments, IReleasePolicy policy, Boolean ignoreParentContext)
   at Castle.MicroKernel.DefaultKernel.Resolve(Type service, Arguments arguments)
   at Castle.Windsor.WindsorContainer.Resolve(Type service)
   at Castle.Windsor.MsDependencyInjection.ScopedWindsorServiceProvider.ResolveInstanceOrNull(Type serviceType, Boolean isOptional)
   at Castle.Windsor.MsDependencyInjection.ScopedWindsorServiceProvider.GetServiceInternal(Type serviceType, Boolean isOptional)
   at Castle.Windsor.MsDependencyInjection.ScopedWindsorServiceProvider.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetService[T](IServiceProvider provider)
   at Microsoft.AspNetCore.SignalR.Internal.DefaultHubActivator`1.Create()
   at Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher`1.OnDisconnectedAsync(HubConnectionContext connection, Exception exception)
   at Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher`1.OnDisconnectedAsync(HubConnectionContext connection, Exception exception)
   at Microsoft.AspNetCore.SignalR.HubConnectionHandler`1.HubOnDisconnectedAsync(HubConnectionContext connection, Exception exception)
ERROR 2020-05-05 14:31:23,331 [25   ] nnections.Internal.HttpConnectionManager - Failed disposing connection vmQKhULyuU2ahIdSm_Kglw.
System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'Scope was already disposed. This is most likely a bug in the calling code.'.
   at Castle.MicroKernel.Lifestyle.ScopedLifestyleManager.GetScope(CreationContext context)
   at Castle.MicroKernel.Lifestyle.ScopedLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.Windsor.MsDependencyInjection.MsScopedLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.MicroKernel.Handlers.DefaultHandler.ResolveCore(CreationContext context, Boolean requiresDecommission, Boolean instanceRequired, Burden& burden)
   at Castle.MicroKernel.Handlers.DefaultHandler.Resolve(CreationContext context, Boolean instanceRequired)
   at Castle.MicroKernel.Handlers.AbstractHandler.Resolve(CreationContext context)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernelByType(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernel(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveCore(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.Resolve(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.CreateConstructorArguments(ConstructorCandidate constructor, CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.Instantiate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.InternalCreate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.AbstractComponentActivator.Create(CreationContext context, Burden burden)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.CreateInstance(CreationContext context, Boolean trackedExternally)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.MicroKernel.Handlers.DefaultHandler.ResolveCore(CreationContext context, Boolean requiresDecommission, Boolean instanceRequired, Burden& burden)
   at Castle.MicroKernel.Handlers.DefaultHandler.Resolve(CreationContext context, Boolean instanceRequired)
   at Castle.MicroKernel.Handlers.AbstractHandler.Resolve(CreationContext context)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernelByType(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveFromKernel(CreationContext context, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.ResolveCore(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.Resolvers.DefaultDependencyResolver.Resolve(CreationContext context, ISubDependencyResolver contextHandlerResolver, ComponentModel model, DependencyModel dependency)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.CreateConstructorArguments(ConstructorCandidate constructor, CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.Instantiate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.DefaultComponentActivator.InternalCreate(CreationContext context)
   at Castle.MicroKernel.ComponentActivator.AbstractComponentActivator.Create(CreationContext context, Burden burden)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.CreateInstance(CreationContext context, Boolean trackedExternally)
   at Castle.MicroKernel.Lifestyle.AbstractLifestyleManager.Resolve(CreationContext context, IReleasePolicy releasePolicy)
   at Castle.MicroKernel.Handlers.DefaultHandler.ResolveCore(CreationContext context, Boolean requiresDecommission, Boolean instanceRequired, Burden& burden)
   at Castle.MicroKernel.Handlers.DefaultHandler.Resolve(CreationContext context, Boolean instanceRequired)
   at Castle.MicroKernel.Handlers.AbstractHandler.Resolve(CreationContext context)
   at Castle.MicroKernel.DefaultKernel.ResolveComponent(IHandler handler, Type service, Arguments additionalArguments, IReleasePolicy policy, Boolean ignoreParentContext)
   at Castle.MicroKernel.DefaultKernel.Castle.MicroKernel.IKernelInternal.Resolve(Type service, Arguments arguments, IReleasePolicy policy, Boolean ignoreParentContext)
   at Castle.MicroKernel.DefaultKernel.Resolve(Type service, Arguments arguments)
   at Castle.Windsor.WindsorContainer.Resolve(Type service)
   at Castle.Windsor.MsDependencyInjection.ScopedWindsorServiceProvider.ResolveInstanceOrNull(Type serviceType, Boolean isOptional)
   at Castle.Windsor.MsDependencyInjection.ScopedWindsorServiceProvider.GetServiceInternal(Type serviceType, Boolean isOptional)
   at Castle.Windsor.MsDependencyInjection.ScopedWindsorServiceProvider.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetService[T](IServiceProvider provider)
   at Microsoft.AspNetCore.SignalR.Internal.DefaultHubActivator`1.Create()
   at Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher`1.OnDisconnectedAsync(HubConnectionContext connection, Exception exception)
   at Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher`1.OnDisconnectedAsync(HubConnectionContext connection, Exception exception)
   at Microsoft.AspNetCore.SignalR.HubConnectionHandler`1.HubOnDisconnectedAsync(HubConnectionContext connection, Exception exception)
   at Microsoft.AspNetCore.SignalR.HubConnectionHandler`1.RunHubAsync(HubConnectionContext connection)
   at Microsoft.AspNetCore.SignalR.HubConnectionHandler`1.OnConnectedAsync(ConnectionContext connection)
   at Microsoft.AspNetCore.SignalR.HubConnectionHandler`1.OnConnectedAsync(ConnectionContext connection)
   at Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.ExecuteApplication(ConnectionDelegate connectionDelegate)
   at Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.WaitOnTasks(Task applicationTask, Task transportTask, Boolean closeGracefully)
   at Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.DisposeAsync(Boolean closeGracefully)
   at Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager.DisposeAndRemoveAsync(HttpConnectionContext connection, Boolean closeGracefully)
WARN  2020-05-05 14:31:23,388 [8    ] EN_SOFT.MyApp.Web.Chat.SignalR.ChatHub - Abp.AbpException: Unknown filter name: MayHaveTenant. Be sure this filter is registered before.
   at Abp.Domain.Uow.UnitOfWorkBase.GetFilterIndex(String filterName)
   at Abp.Domain.Uow.UnitOfWorkBase.SetFilterParameter(String filterName, String parameterName, Object value)
   at Abp.Domain.Uow.UnitOfWorkBase.SetTenantId(Nullable`1 tenantId, Boolean switchMustHaveTenantEnableDisable)
   at Abp.Domain.Uow.UnitOfWorkBase.Begin(UnitOfWorkOptions options)
   at Abp.Domain.Uow.UnitOfWorkManager.Begin(UnitOfWorkOptions options)
   at Abp.Domain.Uow.UnitOfWorkInterceptor.InterceptSynchronous(IInvocation invocation)
   at Castle.DynamicProxy.AsyncDeterminationInterceptor.Intercept(IInvocation invocation)
   at Castle.DynamicProxy.AbstractInvocation.Proceed()
   at Castle.Proxies.UserFriendsCacheProxy.GetCacheItem(UserIdentifier userIdentifier)
   at MyCompany.MyApp.Friendships.ChatUserStateWatcher.NotifyUserConnectionStateChange(UserIdentifier user, Boolean isConnected) in D:\a\1\s\aspnet-core\src\MyCompany.MyApp.Core\Friendships\ChatUserStateWatcher.cs:line 45
   at MyCompany.MyApp.Friendships.ChatUserStateWatcher.OnlineClientManager_UserDisconnected(Object sender, OnlineUserEventArgs e) in D:\a\1\s\aspnet-core\src\MyCompany.MyApp.Core\Friendships\ChatUserStateWatcher.cs:line 41
   at Abp.RealTime.OnlineClientManager.Remove(String connectionId)
   at Abp.AspNetCore.SignalR.Hubs.OnlineClientHubBase.OnDisconnectedAsync(Exception exception)

HAve you seen this before ? Is there a link with CPU consumption ?


13 Answer(s)
  • 0
    ismcagdas created
    Support Team

    Hi @ricavir

    Do you use SignalR actively ? If not, you can disable it as a quick solution by commenting out the related code blocks.

  • 0
    ricavir created

    Hi @ismcagdas,

    SignalR is being used from angular and xamarin apps. I can't just deactivate it. The problem is that it is really not predictable how CPU charge is evolving...and all logs are pointing to SignalR exception. But as you know, these SignalR exception logs are happening several times per day and without impacting CPU charge most of time. Therefore, I'm not sure if that is the cause...

    Really, I don't how to fix this.

  • 0
    ricavir created

    @ismcagdas,

    I found this kind of lines in the logs that matches the CPU charge spikes :

    FATAL 2020-05-07 11:53:28,813 [1    ] Microsoft.AspNetCore.Hosting.Diagnostics - Hosting startup assembly exception
    System.InvalidOperationException: Startup assembly Microsoft.AspNetCore.AzureAppServices.HostingStartup failed to execute. See the inner exception for more details.
     ---> System.IO.FileNotFoundException: Could not load file or assembly 'Microsoft.AspNetCore.AzureAppServices.HostingStartup, Culture=neutral, PublicKeyToken=null'. The system cannot find the file specified.
    File name: 'Microsoft.AspNetCore.AzureAppServices.HostingStartup, Culture=neutral, PublicKeyToken=null'
       at System.Reflection.RuntimeAssembly.nLoad(AssemblyName fileName, String codeBase, RuntimeAssembly assemblyContext, StackCrawlMark& stackMark, Boolean throwOnFileNotFound, AssemblyLoadContext assemblyLoadContext)
       at System.Reflection.RuntimeAssembly.InternalLoadAssemblyName(AssemblyName assemblyRef, StackCrawlMark& stackMark, AssemblyLoadContext assemblyLoadContext)
       at System.Reflection.Assembly.Load(AssemblyName assemblyRef, StackCrawlMark& stackMark, AssemblyLoadContext assemblyLoadContext)
       at System.Reflection.Assembly.Load(AssemblyName assemblyRef)
       at Microsoft.AspNetCore.Hosting.WebHostBuilder.BuildCommonServices(AggregateException& hostingStartupErrors)
    

    I found a related issue on github here : https://github.com/dotnet/aspnetcore/issues/14547

    Did you faced same issues ?

  • 0
    ismcagdas created
    Support Team

    Hi,

    It seems like you had this problem before https://support.aspnetzero.com/QA/Questions/4911 :). Maybe you can request detailed logs from Azure about this error.

  • 0
    ricavir created

    Ahah, yes you are right ! This time, I don't have nuget packages to update.

    I found others related issues https://github.com/dotnet/extensions/issues/2566 https://github.com/dotnet/aspnetcore/issues/20617

    I applied a workarround by adding a reference to Microsoft.AspNetCore.AzureAppServicesIntegration but the issue is still here.

    A fix is planned for next .net core version 3.1.4...

    I will ask support to azure team and provide a workarround if find any

  • 0
    ismcagdas created
    Support Team

    Thanks @ricavir

    I will leave this open and see if 3.1.4 solves your problem.

  • 0
    ervingayle created

    @ricavir are you still getting this error? I am experiencing it and it is quite frustrating.

    @ismcagdas, How could I test disabling signalr?

  • 0
    ismcagdas created
    Support Team

    Hi @ervingayle

    If you think it is realated to SignalR, you can set abp.signalr.maxTries to 1 in your app, so SignalR will not try to reconnect if connection fails.

  • 0
    ervingayle created

    @ismcagdas,

    I thought it was related to signal but dont explicitly see that in the logs. I do have high memory and cpu usage when loading the homepage and have the HostingStartup error. However I am not exactly sure

  • 0
    ricavir created

    Hi,

    I had an Azure support ticket opened untill yesterday. We monitored the app actively and found several issues.

    The most important one was not logged : it was a crash due to EF Core 3.1. My app has ben migrated to ASP.NET Core 3.1 some weeks ago ; as you know, some refactoring is needed due to EF Core breaking changes... Despite all of our tests during this migration, we miss to test one special case where the app was deleting database items > we noticed the app crashed wihtout any logs causing a 100% CPU due to app restart ! By replacing EF method DeleteAsync by HardDeleteAsync, we fixed this BIG issue. The only clue that we had from the monitoring was an exception 0xC00000FD Stack overflow... Of course, before finding this issue, we search within the app logs to find something strange ; and as you also mentioned, a lot of ERROR and WARNING logs are not affecting the app at all. We lost a lot of time arround them :(

    This was the root cause of this ticket. Honestly, we lost a lot of confidence on our app as this was happening in production and affecting all users. Particularly on EF Core side and Log management.

    We also fixed some other issues arround SignalR specially on client side for reconnection (following ASP.NET Zero code base).

    I'm closing this ticket as it is resolved from our side.

    @ervingayle, if you have any question, feel free to ask :)

  • 0
    ervingayle created

    Hi @ricavir,

    How did you get to a point to identify this problem? Our current issue is with the /AbpServiceProxies/GetAll. There is a corelation between the 100% cpu use and a request to the login page where that javascript is referenced. As a result my users cannot login via the website.

    I have already blindly upgraded the azure app service plan with no luck.

  • 0
    ricavir created

    Hi @ervingayle,

    A user pointed out an issue while saving an entity with specific data. After analysis in debug, we figured out the app crash leading to 100% CPU consumption. I think the problem is wihtin your code. Try to look at your specific code in comparison with zero code basis ; and be careful with EF Core 3.x...

  • 0
    ervingayle created

    @ricavir

    Thanks for your advice. I will take a look as best I can but it is not clear at all. Your scenario involved users taking an action. In my case its a simplistic issue that is preventing login that is not clearly identiifed in the tools I have used to upgrade abp versions in the past.