IIS Process Failure - 502.5 request pipeline

С выходом ASP.NET Core 2.0 становится понятно, что новая платформа всё прочнее входит в наши реалии разработки, а значит пора начинать с ней знакомиться. Но начать мне бы хотелось не с разработки традиционных Hello world приложений и успешных сценариев, а наоборот, с отказа. И так уж случилось, что эта заметка станет в большей степени некоторым research’ем поведения IIS’а и лишь вскользь затронет AspNetCoreModule.

Если прямо сейчас создать новый Web Application в Visual Studio 17 (15.3) для платформы ASP.NET Core 2.0, то в файле Program.cs можно будет увидеть следующее:

public class Program
{
    public static void Main(string[] args)
    {
        BuildWebHost(args).Run();
    }

    public static IWebHost BuildWebHost(string[] args) =>
        WebHost.CreateDefaultBuilder(args)
            .UseStartup<Startup>()
            .Build();
}

Как мы уже знаем из многочисленных видео с конференции .NET Conf 2017 данный код является отправной точкой и каркасом нашего приложения.

Признаться, первоначальной темой для заметки я хотел выбрать обзор того, что же происходит в данных строчках, однако мысль “а что если” предопределила дальнейшее повествование. И заключается она в том, чтобы закомментировать содержимое метода Main (который с недавних пор может быть помечен ключевым словом async) и посмотреть что будет.

Сказано- сделано. И вот к чему это нас привело:

Вопрос который возник у меня,- откуда берётся содержимое этой ошибки, кто ответственен за её возврат и что же происходит за ширмой. Очевидно, что начать следует с запущенного процесса IIS и чтобы как-то его идентифицировать, направляемся в свойства проекта.

Из информации о запуске проекта мы видим, что наше приложение использует IIS Express (и к слову, запускается так же копия приложения для HTTPS, слушаюшая 44319 порт).

Корневым каталогом для нашего веб-сервера является путь C:\Users\<Username>\Documents\IISExpress.

Для начала убедимся что IIS действительно обрабатывал запрос и вернул соответствующий код ошибки. Для этого смотрим содержимое папки logs:

Так и есть- содержимое лога красноричиво нам заявляет, что, дескать, были запросы по адресу / и код ответа по ним был возвращен 502 5.

Далее рассмотрим содержимое папки TraceLogFiles.

В моём случае в ней находятся 2 файла, каждый из которых содержит подробную информацию о событиях связанных с конкретным HTTP запросом. Я сперва был несколько удивлён почему их два, но присмотревшись всё оказалось довольно просто- наличие второго является следствием обращения к favicon.ico. Проанализировав содержимое становится очевидно, что наш запрос в конце концов поступает на обработку в модуль AspNetCoreModule:

При поиске по исходникам этого модуля находим как содержимое ошибки так и код его добавления в тело ответа от сервера:

if (SUCCEEDED(pApplicationManager->Get502ErrorPage(&pDataChunk)))
{
    if (FAILED(hr = pResponse->WriteEntityChunkByReference(pDataChunk)))
    {
        goto Finished;
    }
    pResponse->SetStatus(502, "Bad Gateway", 5, hr);
    pResponse->SetHeader("Content-Type",
        "text/html",
        (USHORT)strlen("text/html"),
        FALSE
    );
    goto Finished;
}