IIS Log Parser and important troubleshooting queiries

Understand your IIS Log better

There are cases when even asp.net and sitecore application level logs doesn't provide much of an information.The reason behind is some request is just processed by IIS webserver but never executed at application server i.e sitecore or asp.net pipeline.

This is where HTTP.Sys , Failed Request Tracing and IIS logs comes into picture. This is not when you looking for memory leak or CPU utilization.But this is certain some of the pattern of page execution or 500 internal server exception indirectly contributes to memory leak or CPU utilization. Always visit your IIS logs post performance load test. This will help you align your performance results with incoming request made in IIS.

Long story short. Download log parser studio if you have IIS log to analyze. This is very handy tool.

https://gallery.technet.microsoft.com/office/Log-Parser-Studio-cd458765

Query#1 Http.5xxx

SELECT TO_LOCALTIME( TO_TIMESTAMP( date, time ) ),

    cs-username,

    sc-status,

    sc-substatus,

    cs-uri-stem,

    time-taken as time_taken_MS,

    DIV(time-taken,60000) as timetaken_MM,

    cs-method, 

    cs-uri-query ,

    Count(*) AS Total

    From '[LOGFILEPATH]'

    Where sc-status = 500

    Group By cs-username, sc-status, cs-uri-stem, cs-uri-query,date,time,cs-method, cs-uri-query ,time-taken,sc-substatus

Query#2:/*  Count and sort all HTTP status codes */

Remember http status code below have apended http SUB STATUS CODE

SELECT TOP 25  

    STRCAT(TO_STRING(sc-status),  

    STRCAT('.', TO_STRING(sc-substatus))) As Status,  

    COUNT(*) AS Hits  

    FROM '[LOGFILEPATH]'  

GROUP BY Status  

ORDER BY Hits DESC 

Query#3 To find DDOS Attack

A distributed denial-of-service (DDoS)attack occurs when multiple systems flood the bandwidth or resources of a targeted system, usually one or more web servers. Such an attack is often the result of multiple compromised systems (for example, a botnet) flooding the targeted system with traffic.

/* Hits on a particular page by IP address */

select c-ip, count(c-ip) as requestcount 

from '[LOGFILEPATH]' 

where cs-uri-stem like '%/%' 

group by c-ip order by count(c-ip) desc

Sitecore Pipeline HttpBeginRequest and Processor HttpRequestProcessor to Intercept requests before page get processed completely.

Problem Statement:

To intercept each request and check site configuration and take required steps before it is served and processed complete. This can be enabling intermediate maintenance page or site down page in case unfortunate events occurred such as third party service is down . This in particular is the case your content site is more dependent on upstream or downstream application to serve user specific data. Even though you aimed for zero downtime as per your architecture.

Solution:

Approach 1: To check this flag at every action call using action filter in mvc sitecore controller.

Approach 2: To intercept the call before it call action filter.

Reference: Pipeline and its Processor

https://doc.sitecore.net/sitecore_experience_platform/developing/developing_with_sitecore/mvc/mvc_and_pipelines

http://www.sitecorecoffee.com/2016/02/pipelines-sitecore-development-basics.html

Implementation:

Add processor just after ItemResolver to intercept the request to check for sitecore stored flag and take action based on values that something suits your requirement

Pipeline: httpBeginRequest: Sitecore.Pipelines.HttpRequest

Key Notes:

• Ensure you have proper patch insert for CD and delete for CM. As per the scenario.
• Ensure you have AbortPipeline in place to prevent -Cascading response header issue- Such as append header and results in Too many redirects.
• Use custom processor wisely and regression test to cover different use case across the page navigation involves logout /login [For transactional Site or Personalised site]

Maintenance Page Take App Offline! Magic with App_Offline.htm

Overview

The App_offline thing is around for quiet long time and I haven't seen enterprise level system use it. Either they do it using at load balancer end or redirect to some third party hamster page until the site is provision for up and running. Leaving the real time usage and know-how.

Headstart

Refer this: http://geekswithblogs.net/Vipin/archive/2012/03/28/app_offline.htm-taking-site-down-for-maintenance.aspx

Here are quick help tip if you want to enable it.

Key Note

Remember just putting App_offline.htm in the root folder of the website will just stop the further processing of request and always return =

Http Status 503:

The service is unavailable.

If you really want to show up App_Offline.htm custom page you must add this in your web.config file

Refer this for more information
https://stackoverflow.com/questions/17135109/app-offline-site-returning-the-service-is-unavailable

One can even try to automate this using FTP command and powershell or either use out of the box option in VSO Build and Release pipeline.

https://stackoverflow.com/questions/20792405/how-to-take-web-app-offline-while-publishing

Take App Offline option under Deployment

Gotcha ! Special Character & in web.config

What is special about &?

Whenever you're dealing with ampersand or querystring url in rewrite rules beware of special character "&". There are chances you may play around with different ways to make it working. Inline rewritemap maps things bit difficult. Yes it might happen you have few rewrite and you end up with inline rewrite in web.config. Careful watch rewritemap urls as these may content special character as part of URI and redirection symantics. Sometimes # results in error and exception.

Always try this!

• Replace & with &Make use of html encode and decode instead of URL Encode value such as "%26"
• Good practice to keep rewritemap outside web.config . In many scenario the URL encode for ampersand as well # in querystring works.

References:

https://stackoverflow.com/questions/7094846/rewriting-ampersand-urls-with-iis-7-rewriting-module

http://ruslany.net/2010/05/storing-url-rewrite-mappings-in-a-separate-file/

Sitecore CMS Logout not working due to conflicting Authentication Controller

Introduction

Sitecore CMS Logout will throw Javascript error due to multiple controller named 'Authentication'

Sitecore Logs
10344 02:57:52 ERROR Application error.
Exception: System.InvalidOperationException
Message: Multiple types were found that match the controller named 'Authentication'. This can happen if the route that services this request ('sitecore/shell/api/sitecore/{controller}/{action}') does not specify namespaces to search for a controller that matches the request. If this is the case, register this route by calling an overload of the 'MapRoute' method that takes a 'namespaces' parameter.

The request for 'Authentication' has found the following matching controllers:
Sitecore.Controllers.AuthenticationController
MyWebsite.MyArea.Controllers.Api.AuthenticationController
Source: System.Web.Mvc
   at System.Web.Mvc.DefaultControllerFactory.GetControllerTypeWithinNamespaces(RouteBase route, String controllerName, HashSet`1 namespaces)
   at System.Web.Mvc.DefaultControllerFactory.GetControllerType(RequestContext requestContext, String controllerName)
   at System.Web.Mvc.DefaultControllerFactory.System.Web.Mvc.IControllerFactory.GetControllerSessionBehavior(RequestContext requestContext, String controllerName)
   at System.Web.Mvc.MvcRouteHandler.GetHttpHandler(RequestContext requestContext)
   at Sitecore.Mvc.Routing.RouteHandlerWrapper.GetHttpHandler(RequestContext requestContext)
   at System.Web.Routing.UrlRoutingModule.PostResolveRequestCache(HttpContextBase context)
   at System.Web.HttpApplication.SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)


Resolution

1. Either rename your custom controller from Authentication to something Account to avoid sitecore conflict.
2. Else apply below Maproute.

public override void RegisterArea(AreaRegistrationContext context) 
       {           
           context.MapRoute(
            "SCAuth",
              "sitecore/shell/api/sitecore/{controller}/{action}",
              new { controller = "Authentication", action = "Index" },
              new[] { "Sitecore.Controllers" });
 
 
       }

Reference:
https://sitecore.stackexchange.com/questions/201/how-to-override-replace-the-default-sitecore-authentication-controller

Sitecore .Net File Change Notification Shut down issues

 

Problem Statement

Not sure what is causing file change in webapps whether it is appinsight or for that matter logging handler that keep adding debug, info and error traces, cache or something else. For some reason there is something going under the hood which causes this file change notification. This take me back to the basics of file change notification causes app pool recycle when there is change in web.config or global.asax. Now as best practice it is always mentioned the logging has to be done outside your webroot and for some reason this is not the case with webapp. I'm naïve in webapp world and file and drive structure in azure webapp paas environment. Those days are gone when you use to have full control of VMs and you can deep dive into solving and identifying issues.

KB: Sitecore stability issues when using Azure Web Apps

https://kb.sitecore.net/articles/983839

It talks about dynamic cache- WEBSITE_DYNAMIC_CACHE

FCN Cause and Effect

Now this file change notification itself is a problem which as ripple effect on few things. This is how it works.

Chain and sequences of events due to FCN- Filewatcher/File change notification

1. File change notification, filewatcher notification triggers
2. Sitecore shut down
3. Solr or lucene Indexing lookup failed. Empty Index found.
4. Session State, if sql , Redis or Mongo used: Failure of session state, results in session leaks and session_end events, and all other subsequent calls.
5. XDb: Analytics current tracking failed or current tracking is null
6. Eventually spike in CPU utilization and memory leaks.

How it goes?

FCN Cause -> Affected--> Sitecore shut down-> Session --> Indexing--> Analytics-> CPU utilization--> Memory Leaks

It is very important to understand how we approach to the problem and how we look up error logs. It is not that straight forward instead need problem occurrence chart[Fish bone technique to lay down the cause and effect] to note down each events. In fact I see this as solving mystery or identify suspects. Like above chain of sequence. As rule of thumb memory leaks and CPU utilization always leads you to bad code or DI leaks etc. I insist more lateral thinking than primitive way of identifying problem.

.Net Way Short term Workaround: Brute force Fixes

http://www.dnnsoftware.com/community-blog/cid/154980/aspnet-file-change-notifications-and-dnn

https://shazwazza.com/post/all-about-aspnet-file-change-notification-fcn/

https://blogs.msdn.microsoft.com/tmarq/2007/11/01/asp-net-file-change-notifications-exactly-which-files-and-directories-are-monitored/

https://stackoverflow.com/questions/37039727/azure-web-app-worker-process-recycling-unexpectedly

As a work-around I have added fcnMode = "Disabled" to the httpRuntime element in the web.config. The root cause remains unknown.

httpruntime fcnmode="Disabled"/