Analyzing request log for an MVC application, strange things found?

Last post 10-15-2008 4:06 AM by Vladan Strigo. 1 replies.

Sort Posts:

  • Analyzing request log for an MVC application, strange things found?

    10-13-2008, 8:16 AM
    • Participant
      1,010 point Participant
    • Vladan Strigo
    • Member since 01-19-2003, 7:07 AM
    • Split, Croatia
    • Posts 218

    Having some strange behavior with my UoW implementation which I use in my MVC apps I went in and put Log4Net entries for Application Start, End and Begin and End Request events in global.asax.

    Before I post details from the log, a few words on the setup... Its a vanilla MVC P5 app which only has some simple design (css + couple of images) and has defined routes:


            public override void Application_Start(object sender, EventArgs e)
            {

                log4net.Config.XmlConfigurator.Configure();
                log.Info("Started application!");

                base.Application_Start(sender, e);

                RouteTable.Routes.IgnoreRoute("{resource}.axd/{*pathInfo}");
                RouteTable.Routes.IgnoreRoute("{*pathInfo}", new { pathInfo = "^Content\\/.*" });

                RouteTable.Routes.MapRoute("Default",
                                               "{controller}/{action}.aspx/{id}",
                                               new { controller = "Home", action = "Index", id = "" },
                                               new { controller = "[^\\.]*", action = "[^\\.]*" });
            }
     

     My Default.aspx page does in its code behind a redirect:

                Response.Redirect("/Home/index.aspx");


    Here is a copy&paste from the log:

     17:35:37.923 [4] - Started application!
    17:35:38.470 [4] - Registered routes
    17:35:38.752 [4] - Started new request for http://localhost:31607/default.aspx!
    17:35:39.314 [4] - Started new request for http://localhost:31607/default.aspx!
    17:35:39.377 [4] - Ended a request for http://localhost:31607/default.aspx!
    17:35:39.893 [4] - Started new request for http://localhost:31607/Home/index.aspx!
    17:35:39.924 [4] - Started new request for http://localhost:31607/Home/index.aspx!
    17:35:40.753 [4] - Ended a request for http://localhost:31607/Home/index.aspx!
    17:35:40.753 [4] - Ended a request for http://localhost:31607/Home/index.aspx!

    17:35:40.784 [8] - Started new request for http://localhost:31607/Content/Styles/style.css!
    17:35:40.784 [8] - Started new request for http://localhost:31607/Content/Styles/style.css!
    17:35:40.784 [8] - Ended a request for http://localhost:31607/Content/Styles/style.css!
    17:35:40.784 [8] - Ended a request for http://localhost:31607/Content/Styles/style.css!

    17:35:40.800 [4] - Started new request for http://localhost:31607/Content/Images/logo.jpg!
    17:35:40.800 [4] - Started new request for http://localhost:31607/Content/Images/logo.jpg!
    17:35:40.800 [4] - Ended a request for http://localhost:31607/Content/Images/logo.jpg!
    17:35:40.800 [4] - Ended a request for http://localhost:31607/Content/Images/logo.jpg!

    17:35:40.815 [8] - Started new request for http://localhost:31607/Content/Styles/images/topbg.gif!
    17:35:40.815 [8] - Started new request for http://localhost:31607/Content/Styles/images/topbg.gif!

    17:35:40.815 [4] - Started new request for http://localhost:31607/Content/Styles/images/topShadow.jpg!
    17:35:40.815 [4] - Started new request for http://localhost:31607/Content/Styles/images/topShadow.jpg!

    17:35:40.815 [8] - Ended a request for http://localhost:31607/Content/Styles/images/topbg.gif!

    17:35:40.862 [4] - Ended a request for http://localhost:31607/Content/Styles/images/topShadow.jpg!

    17:35:40.862 [9] - Started new request for http://localhost:31607/Content/Styles/images/middleShadow.jpg!

    17:35:40.862 [4] - Started new request for http://localhost:31607/Content/Styles/images/bottomShadow.jpg!

    17:35:40.862 [9] - Started new request for http://localhost:31607/Content/Styles/images/middleShadow.jpg!

    17:35:40.862 [4] - Started new request for http://localhost:31607/Content/Styles/images/bottomShadow.jpg!
    17:35:40.878 [4] - Ended a request for http://localhost:31607/Content/Styles/images/bottomShadow.jpg!

    17:35:40.878 [9] - Ended a request for http://localhost:31607/Content/Styles/images/middleShadow.jpg!

    17:35:43.989 [4] - Started new request for http://localhost:31607/favicon.ico!
    17:35:43.989 [4] - Started new request for http://localhost:31607/favicon.ico!
    17:35:44.005 [4] - Ended a request for http://localhost:31607/favicon.ico!

    22:09:07.421 [8] - Ended application!

     

     Ok, so a couple of questions hidden in remarks to this log:

    •  So, I've setup routes to ignore paths to /Content folder, thus excluding images, js files, css files, etc... from routing... how should this relate to application (notice above that my application events receive also requests for images)? I mean should I then do myself (pseudo):
         if (Request.Url.Contains("/Content")) return; // Thus do not initialize UoW for content files

    • How come that in one call (so one user/browser session) a resource gives 2 requests to the application (from above see that for example we have 2 begin and end requests for Index.aspx or some images)?

    • How come that in some cases we get 2 Begin requests and 1 End request for some resources? I thought that I could always count on if a request gets open (=Begin) that it will get closed as well (= End)?

    • Would it be any better if I've executed the actions from a HttpModule instead of Global? (are there any gurantiees as to execution and calling?)


    Any ideas?



    Thanks,
    Vladan

    Thanks, Vladan Strigo

    My website: Vladan.Strigo.NET
  • Re: Analyzing request log for an MVC application, strange things found?

    10-15-2008, 4:06 AM
    • Participant
      1,010 point Participant
    • Vladan Strigo
    • Member since 01-19-2003, 7:07 AM
    • Split, Croatia
    • Posts 218

     is answer so obvious or?

     does anyone find this unusual as I do?

     

     

    Thanks, Vladan Strigo

    My website: Vladan.Strigo.NET
Page 1 of 1 (2 items)