aspnet / AspNetKatana

Microsoft's OWIN implementation, the Katana project
Apache License 2.0
960 stars 331 forks source link

OWIN Startup class is initializing and disposing in a loop #461

Closed Bykiev closed 2 years ago

Bykiev commented 2 years ago

Hi, I have a strange issue on production server (Windows Server 2012R2, IIS), the OWIN Startup class is initializing and disposing in a loop and app became almost unresponsive. I cannot figure out what can be the coolprit, but on my development PC and our test server it's working fine (it's a Windows 10 and Windows Server 2016). I believe it's a bug in OWIN/IIS. We're hosting our Web API and angular in one site, in new release the bundle and assets size doubled and it seems to be an issue in Windows Server 2012R2. I've spent many hours trying to figure out what can be done on my side, but there is no any info about such issue. Can you please help me with this?

Tratcher commented 2 years ago

Are you able to capture a dump and/or attach a debugger and look at the call stacks?

Do you have any logs?

Startup runs automatically when the app starts up (on first request). Nothing in OWIN triggers an app shutdown, that would have to be IIS. It may be because of a crash. There should be event logs in that case.

Bykiev commented 2 years ago

There is no entries in system event log. I'll try to make a process dump, but I can't attach the debugger. The app is hosting on this server for a long time without such issues, I believe there is smth related to request numbers/size on initial load, but can't catch it

Bykiev commented 2 years ago

I did some more research and if Angular part is removed and only web API is hosted there is no such issues. Seems to be related for initial load (maybe timeout is riched and IIS restarts).

Upd: it seems to be not releated with first call, I've deployed it again with Angular app, made first request with fiddler to Web API all was fine. Then I've opened the angular app via browser and got a restart loop again

Upd2: in event log I've found these entries with WAS source:

A process serving application pool 'MyAppPoolName' exceeded time limits during shut down. The process id was '10376'.

A worker process '10376' serving application pool 'MyAppPoolName' failed to stop a listener channel for protocol 'http' in the allotted time. The data field contains the error number.

Bykiev commented 2 years ago

I did a process dump and there is some interesting information:

ShutDown Reason

BinDirChangeOrDirectoryRename - A change was made to the Bin folder or to files in it

Message

Change Notification for critical directories. 
bin dir change or directory rename 
HostingEnvironment initiated shutdown 
Change Notification for critical directories. 
bin dir change or directory rename 
Change Notification for critical directories. 
bin dir change or directory rename 
Change Notification for critical directories. 
bin dir change or directory rename 
Change Notification for critical directories. 
bin dir change or directory rename 
Change Notification for critical directories. 
bin dir change or directory rename 
HostingEnvironment caused shutdown

ShutDownStack 

 at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo) 
 at System.Environment.get_StackTrace() 
 at System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal() 
 at System.Web.Hosting.HostingEnvironment.InitiateShutdownWithoutDemand() 
 at System.Web.HttpRuntime.ShutdownAppDomain(String stackTrace) 
 at System.Web.HttpRuntime.OnCriticalDirectoryChange(Object sender, FileChangeEvent e) 
 at System.Web.FileChangesMonitor.OnCriticaldirChange(Object sender, FileChangeEvent e) 
 at System.Web.DirectoryMonitor.FireNotifications() 
 at System.Web.Util.WorkItem.CallCallbackWithAssert(WorkItemCallback callback) 
 at System.Web.Util.WorkItem.OnQueueUserWorkItemCompletion(Object state) 
 at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) 
 at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) 
 at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem() 
 at System.Threading.ThreadPoolWorkQueue.Dispatch()

I don't know what is causing such behaviour

Bykiev commented 2 years ago

Finally, I was able to find the root of the issue - it was an antivirus program. After adding site folder to exlusions everything is working as expected. I've used Proceess monitor to find who is writing files in bin folder or changing web.config (it cause app pool recycle) and it was Antivirus process (it scanning all files and if it's 'good' is createss it on hard drive and almost infinite loop with app recycle is occured. Thank you @Tratcher and sorry for spent time, you're really helped!