Медленный процесс в жизненном цикле ASP.NET MVC

Question

Это мой Global.asax.cs. Важно отметить, что я просто выбрасываю некоторые сообщения при выполнении различных событий.

public class MvcApplication : System.Web.HttpApplication
{
    string file_path = "c:/temp/app.out";

    protected void Application_Start() { /* default codes here */ }

    protected void Application_BeginRequest()
    {
        File.AppendAllText(file_path, "BeginRequest starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);
    }
    protected void Application_PreRequestHandlerExecute()
    {
        File.AppendAllText(file_path, "PreRequestHandlerExecute starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);
    }
    protected void Application_PostRequestHandlerExecute()
    {
        File.AppendAllText(file_path, "PostRequestHandlerExecute starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);
    }
    protected void Application_EndRequest()
    {
        File.AppendAllText(file_path, "EndRequest starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);
    }
}

Вот мой контроллер.

public partial class MyController : Controller
{
    [HttpGet]  public ActionResult PlaceOrders()
    {
        System.IO.File.AppendAllText("c:/temp/app.out", "PlaceOrdersGet starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);
        // Logic here.
        return View(vm);
    }
    [HttpPost] public ActionResult PlaceOrders(Orders vm)
    {
        System.IO.File.AppendAllText("c:/temp/app.out", "PlaceOrdersPost starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);
        // Logic here.
        return PlaceOrders();
    }

}

Что сбивает меня с толку, так это информация журнала:

BeginRequest starts at 2018/11/08 04:21:04.900
PreRequestHandlerExecute starts at 2018/11/08 04:21:04.900
PlaceOrdersGet starts at 2018/11/08 04:21:04.900
PostRequestHandlerExecute starts at 2018/11/08 04:21:05.244
EndRequest starts at 2018/11/08 04:21:05.244

BeginRequest starts at 2018/11/08 04:24:52.391
PreRequestHandlerExecute starts at 2018/11/08 04:24:52.407
PlaceOrdersPost starts at 2018/11/08 04:24:55.110
PlaceOrdersGet starts at 2018/11/08 04:24:56.094
PostRequestHandlerExecute starts at 2018/11/08 04:24:56.438
EndRequest starts at 2018/11/08 04:24:56.438

Когда я выполняю GET для PlaceOrders (), первый блок показывает, что PlaceOrdersGet происходит почти мгновенно после PreRequestHandlerExecute. Однако, когда я делаю POST для PlaceOrders, от PreRequestHandlerExecute до PlaceOrdersPost требуется почти 2,7 секунды! Единственное различие между этими двумя блоками состоит в том, что у последнего возвращается ViewModel, а у первого нет.

Я немного просмотрел сеть, но не смог найти какой-либо помощи, чтобы углубиться в эту проблему. Я знаю, что есть этот метод ProcessRequest, который вызывается, но это насколько я мог. Это оказало серьезное негативное влияние на общую производительность.

Буду признателен за любую помощь или простые коды для предоставления дополнительной информации о времени.

Answer 1

Я думаю, что нашел ответ. Да, задержка 2,7 секунды здесь

PreRequestHandlerExecute starts at 2018/11/08 04:24:52.407
PlaceOrdersPost starts at 2018/11/08 04:24:55.110

действительно связано с привязкой модели!

Решение - привязать себя к модели ...

Я просто изменил свое действие HttpPost с

[HttpPost] public ActionResult PlaceOrders(Orders vm)
{
    System.IO.File.AppendAllText("c:/temp/app.out", "PlaceOrdersPost starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);
    // Logic here.
    return PlaceOrders();
}

на следующее:

[HttpPost] public ActionResult PlaceOrders(FormCollection fc)
{
    System.IO.File.AppendAllText("c:/temp/app.out", "PlaceOrdersPost starts at " + DateTime.Now.ToString("yyyy/MM/dd HH:mm:ss.fff") + Environment.NewLine);

    var vm = new Orders();
    // Assign fc to vm here.
    // Logic here.
    return PlaceOrders();
}

И вот журнал, который я получаю:

PreRequestHandlerExecute starts at 2018/11/08 13:27:09.088
PlaceOrdersPost starts at 2018/11/08 13:27:09.106

По крайней мере, теперь есть незначительная задержка от PreRequestHandlerExecute до PlaceOrdersPost.

Answer 2

У меня недостаточно репутации, чтобы комментировать, но насколько велика ваша модель заказов и где вы ее используете? Если это большая модель с коллекциями, и вы заполняете эти коллекции, может потребоваться некоторое время, чтобы модель заполнилась JSON. Насколько я понимаю, для этой модели нет причин, так как вы ее нигде не используете. Попробуйте без модели Orders в своей публикации и посмотрите, сколько времени это займет.