IIS - AppPool의 "Disable Overlapped Recycle" 옵션
IIS의 AppPool 설정에는 "Disable Overlapped Recycle" 옵션이 제공됩니다.
[disallowOverlappingRotation] If true, the application pool recycle will happen such that the existing worker process exits before another worker process is created. Set to true if the worker process loads an application that does not support multiple instances.
ApplicationPoolRecycling.DisallowOverlappingRotation Property
; https://learn.microsoft.com/en-us/dotnet/api/microsoft.web.administration.applicationpoolrecycling.disallowoverlappingrotation?view=iis-dotnet
IIS 6.0 시절부터 제공하던 기능인데요,
Overlapped Recycling
; https://learn.microsoft.com/en-us/previous-versions/iis/6.0-sdk/ms525803(v=vs.90)#overlapped-recycling
간단하게 설명하자면, w3wp.exe가 recycle 되어야 할 시점이 오면 신규 w3wp.exe를 동시에 띄워 요청을 받을 수 있는 준비를 시켜둡니다. 준비가 되면, 이후 요청을 신규 w3wp.exe로 돌리고, 기존 w3wp.exe는 종료 작업에 들어가게 됩니다. 결국, 웹 서비스의 응답 시간 지연을 최소화시키기 위한 수단으로 마련된 옵션인데요, "Disable Overlapped Recycle" 옵션의 기본값이 false이기 때문에 저렇게 동작합니다.
반면, 만약 이 옵션을 true로 설정하게 되면, w3wp.exe를 완전히 종료한 다음에 신규 w3wp.exe를 띄워 서비스를 하는 방식으로 진행됩니다. 그렇다면 종료 후, 신규 프로세스가 서비스를 시작할 수 있는 시점까지 들어오는 요청들은 어떻게 되는 걸까요? 물론, 걱정하지 않으셔도 됩니다. 왜냐하면, TCP 연결에 대한 유지는 커널 드라이버에서 하고 있으므로 새로운 w3wp.exe가 서비스를 시작하게 되었을 때 IIS 커널 드라이버가 신규 worker process에 요청을 배분하기 때문입니다.
자, 그럼 대충 저 의미는 아셨겠죠? ^^
대개의 경우, 이 옵션은 기본값 false를 두는 것이 좋습니다. 하지만 여전히, 의문점이 하나 남습니다. Recycle 시 IIS 커널 레벨에서 신규 w3wp.exe로 요청을 전달하는 순간이 언제냐... 하는 것인데요, 대충 다음과 같이 시점을 나눠 예측해 볼 수 있습니다.
- ("Start Mode" == AlwaysRunning 옵션의) w3wp.exe의 네이티브 모듈이 모두 올라온 시점
- [.NET Framework만 적용] (PreApplicationStartMethod가 호출되는) .NET 런타임이 초기화된 시점
- ASP.NET Pipeline이 구성된 시점, 즉 ASP.NET 런타임이 초기화된 시점
- Application Initialization이 완료된 시점, 즉 preloadEnabled + initializationPage 요청이 완료된 시점
만약, 1번 단계에서 요청을 넘겨준다면 마찬가지로 그 프로세스로 향하는 첫 번째 요청은 원치 않는 응답 지연 현상에 걸릴 것입니다. 혹은, 3번과 같은 경우라면 기타 ASP.NET 런타임 모듈들이 모두 올라와서 꽤나 지연 현상을 줄일 수 있습니다. 물론, 가장 이상적인 것은 "/" 요청 및 initializationPage로 명시한 요청들이 완료된 이후에 이뤄지는 4번일 것입니다.
예측만 하면 재미가 없죠. ^^ 확인을 위해, 간단하게 테스트를 해보면 됩니다.
예제는 지난 글에 web.config 내 initializationPage까지 구성한 사이트를 재활용하고, 추가로 global.asax.cs의 Application 이벤트에 Log를 남기도록 한 후,
using System;
using System.Web;
using System.Web.Http;
using System.Web.Mvc;
using System.Web.Optimization;
using System.Web.Routing;
using WebApplication2.Controllers;
namespace WebApplication2
{
public class WebApiApplication : System.Web.HttpApplication
{
protected void Application_Start()
{
Log("Application_Start (Start)");
AreaRegistration.RegisterAllAreas();
GlobalConfiguration.Configure(WebApiConfig.Register);
FilterConfig.RegisterGlobalFilters(GlobalFilters.Filters);
RouteConfig.RegisterRoutes(RouteTable.Routes);
BundleConfig.RegisterBundles(BundleTable.Bundles);
Log("Application_Start (End)");
}
protected virtual void Application_BeginRequest()
{
Log("Application_BeginRequest: " + HttpContext.Current.Request.RawUrl);
}
protected virtual void Application_Disposed()
{
Log("Application_Disposed");
}
protected virtual void Application_End()
{
Log("Application_End");
}
public static void Log(string message)
{
System.Diagnostics.Trace.WriteLine($"[{DateTime.Now}, {ValuesController.ProcessId}] WebApplication2 - {message}");
}
}
}
실행을 하고, 동시에 해당 웹 사이트에 /api/values 요청을 1초 간격으로 보내는 클라이언트를 준비합니다. 그럼, 대충 이런 식으로 로그가 남게 될 것입니다.
[5708] [2024-01-05 오후 09:45:19, 5708] WebApplication2 - Application_BeginRequest: /api/values
[5708] [2024-01-05 오후 09:45:20, 5708] WebApplication2 - Application_BeginRequest: /api/values
[5708] [2024-01-05 오후 09:45:21, 5708] WebApplication2 - Application_BeginRequest: /api/values
[5708] [2024-01-05 오후 09:45:22, 5708] WebApplication2 - Application_BeginRequest: /api/values
그러다, IIS 관리자에서 Recycle을 시키면 이렇게 로그가 남게 됩니다.
[1912] [2024-01-05 오후 09:45:23, 1912] WebApplication2 - Application_Start (Start)
[1912] [2024-01-05 오후 09:45:23, 1912] WebApplication2 - Application_Start (End)
[1912] [2024-01-05 오후 09:45:23, 1912] WebApplication2 - Application_BeginRequest: /
[1912] [2024-01-05 오후 09:45:23, 1912] WebApplication2 - Application_BeginRequest: /api/Values
[5708] [2024-01-05 오후 09:45:23, 5708] WebApplication2 - Application_BeginRequest: /api/values
[5708] [2024-01-05 오후 09:45:24, 5708] WebApplication2 - Application_BeginRequest: /api/values
[1912] [2024-01-05 오후 09:45:25, 1912] WebApplication2 - Application_BeginRequest: /api/values
[1912] [2024-01-05 오후 09:45:26, 1912] WebApplication2 - Application_BeginRequest: /api/values
[1912] [2024-01-05 오후 09:45:27, 1912] WebApplication2 - Application_BeginRequest: /api/values
[1912] [2024-01-05 오후 09:45:28, 1912] WebApplication2 - Application_BeginRequest: /api/values
[1912] [2024-01-05 오후 09:45:29, 1912] WebApplication2 - Application_BeginRequest: /api/values
[1912] [2024-01-05 오후 09:45:30, 1912] WebApplication2 - Application_BeginRequest: /api/values
해석이 되시나요? bold 폰트인 1912 프로세스가 새로 뜬 w3wp.exe인데 "/" 요청과 "initializationPage"로 설정한 "/api/Values" 요청이 23초까지 진행되었습니다. 하지만, 여전히 23초와 24초에 1초 간격으로 발생하던 클라이언트의 요청은 5708 프로세스, 즉 기존에 서비스 중이던 w3wp.exe에서 받아서 처리하고 있습니다.
그리고, 이후 25초부터는 완벽히 초기화를 마친 1912 프로세스가 요청을 전담하고 있습니다. 뭐, 이 정도면 완벽한 ^^ 수준이죠?
예전에는, Cold Start 시의 응답 시간 지연 현상을 어떻게라도 없애기 위해 심지어 자동 재생을 끄는 것도 고려를 하는 경우가 있었습니다.
IIS 작업자 프로세스의 20분 자동 재생(Recycle)을 끄는 방법
; https://www.sysnet.pe.kr/2/0/1774
하지만, 이제는 "Disable Overlapped Recycle" 옵션과 함께 IIS 8.0의 "
preload Enabled" 설정이 있으므로 저렇게 할 필요가 없어졌습니다.
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]