Sitecore XM Cloud, Ordercloud, CDP, Personalize, ContentHub and Send: Sitecore and AWS

Hi All,

From some time we have been facing some issue where while accessing the site it's giving 504 and 404 errors.

This Sitecore instance setup in AWS cloud.

We have first captured below error log but not found much useful.

28464 11:22:01 WARN Protected page accessed with no current user
28464 11:22:01 ERROR Application error.
Exception: System.Web.HttpUnhandledException
Message: An unhandled exception occurred.
Source: Sitecore.Mvc
at Sitecore.Mvc.Pipelines.MvcEvents.Exception.ShowAspNetErrorMessage.ShowErrorMessage(ExceptionContext exceptionContext, ExceptionArgs args)
at Sitecore.Mvc.Pipelines.MvcEvents.Exception.ShowAspNetErrorMessage.Process(ExceptionArgs args)
at (Object , Object[] )
at Sitecore.Pipelines.CorePipeline.Run(PipelineArgs args)
at Sitecore.Mvc.Pipelines.PipelineService.RunPipeline[TArgs](String pipelineName, TArgs args)
at Sitecore.Mvc.Filters.PipelineBasedRequestFilter.OnException(ExceptionContext exceptionContext)
at System.Web.Mvc.ControllerActionInvoker.InvokeExceptionFilters(ControllerContext controllerContext, IList`1 filters, Exception exception)
at System.Web.Mvc.ControllerActionInvoker.InvokeAction(ControllerContext controllerContext, String actionName)
at Sitecore.Mvc.Controllers.SitecoreActionInvoker.InvokeAction(ControllerContext controllerContext, String actionName)
at System.Web.Mvc.Controller.<>c__DisplayClass22.b__1e()
at System.Web.Mvc.Async.AsyncResultWrapper.<.cctor>b__0(IAsyncResult asyncResult, Action action)
at System.Web.Mvc.Async.AsyncResultWrapper.End(IAsyncResult asyncResult, Object tag)
at System.Web.Mvc.Controller.EndExecuteCore(IAsyncResult asyncResult)
at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)
at System.Web.Mvc.Async.AsyncResultWrapper.End(IAsyncResult asyncResult, Object tag)
at System.Web.Mvc.MvcHandler.b__5(IAsyncResult asyncResult, ProcessRequestState innerState)
at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)
at System.Web.Mvc.Async.AsyncResultWrapper.End(IAsyncResult asyncResult, Object tag)
at System.Web.Mvc.MvcHandler.EndProcessRequest(IAsyncResult asyncResult)
at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.EndProcessRequest(IAsyncResult result)
at Sitecore.Mvc.Routing.RouteHttpHandler.EndProcessRequest(IAsyncResult result)
at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Nested Exception

Exception: System.InvalidOperationException
Message: Error while rendering view: '/sitecore/shell/client/Speak/Layouts/Layouts/Speak-Layout.cshtml' (model: 'Sitecore.Mvc.Presentation.RenderingModel, Sitecore.Mvc').

Source: Sitecore.Mvc
at Sitecore.Mvc.Presentation.ViewRenderer.Render(TextWriter writer)
at Sitecore.Mvc.Pipelines.Response.RenderRendering.ExecuteRenderer.Render(Renderer renderer, TextWriter writer, RenderRenderingArgs args)
at Sitecore.Mvc.Pipelines.Response.RenderRendering.ExecuteRenderer.Process(RenderRenderingArgs args)
at (Object , Object[] )
at Sitecore.Pipelines.CorePipeline.Run(PipelineArgs args)
at Sitecore.Mvc.Pipelines.PipelineService.RunPipeline[TArgs](String pipelineName, TArgs args)
at Sitecore.Mvc.Presentation.RenderingView.Render(ViewContext viewContext, TextWriter writer)
at System.Web.Mvc.ViewResultBase.ExecuteResult(ControllerContext context)
at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters(ControllerContext controllerContext, IList`1 filters, ActionResult actionResult)
at System.Web.Mvc.ControllerActionInvoker.InvokeAction(ControllerContext controllerContext, String actionName)

Second Identification:-

Overriding expired contact session lock. This typically means the previous request for the contact did not release session state properly or is taking too long to execute.

· WARN Overriding expired contact session lock for contact id: c855c633-7974-44a8-b436-6da08dc1743e

For this, we have reviewed all articles -

Third Identification:-

Line 105: Message: The remote host closed the connection. The error code is 0x800704CD.

Search "error" (15 hits in 1 file)

C:\Users\jitendra.so\Desktop\aa\Log.txt (15 hits)

Line 30: 2017-08-29 11:22:01 Req:f399a9ec-a07e-4 Host:SIT01 Url:/sitecore/shell/Applications/Content Editor.aspx?sc_bw=1 SID: sitecore\Usera 28464 ERROR Application error.

Line 30: 2017-08-29 11:22:01 Req:f399a9ec-a07e-4 Host:IT01 Url:/sitecore/shell/Applications/Content Editor.aspx?sc_bw=1 SID: sitecore\Usera28464 ERROR Application error.

Line 34: at Sitecore.Mvc.Pipelines.MvcEvents.Exception.ShowAspNetErrorMessage.ShowErrorMessage(ExceptionContext exceptionContext, ExceptionArgs args)

Line 35: at Sitecore.Mvc.Pipelines.MvcEvents.Exception.ShowAspNetErrorMessage.Process(ExceptionArgs args)

Line 61: Message: Error while rendering view: '/sitecore/shell/client/Speak/Layouts/Layouts/Speak-Layout.cshtml' (model: 'Sitecore.Mvc.Presentation.RenderingModel, Sitecore.Mvc').

Line 81: Message: Error while rendering view: '/sitecore/shell/client/Speak/Layouts/Renderings/Common/PageCodes/PageCode.cshtml' (model: 'Sitecore.Mvc.Presentation.RenderingModel, Sitecore.Mvc').

Line 105: Message: The remote host closed the connection. The error code is 0x800704CD.

Line 107: at System.Web.Hosting.IIS7WorkerRequest.RaiseCommunicationError(Int32 result, Boolean throwOnDisconnect)

Line 125: 2017-08-29 11:22:25 Req:f93acb95-a1e9-4 Host:SIT01 Url:/ SID: default\Anonymous 28444 INFO Trace: log4net:ERROR [SitecoreLogFileAppenderExtension] Exception while rolling file [C:\Inetpub\wwwroot\CMMANUTD\Data\logs\CommonLog.log20170829.11.txt] -> [C:\Inetpub\wwwroot\CMMANUTD\Data\logs\CommonLog.log20170829.11.txt.1]

Line 127: at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)

We have also analyze the below query

Url:/sitecore/login__Data:__EVENTTARGET=, __EVENTARGUMENT=, __VIEWSTATE=/wEP SID: default\Anonymous 29612 INFO AUDIT (sitecore\admin): Login

Url:/sitecore/service/keepalive.aspx?ts=8974257 SID: sitecore\User1 21020 INFO HttpModule is being initialized

SID: sitecore\admin 15668 INFO AUDIT (sitecore\Anonymous): Logout: sitecore\UserB.

if you see the above error there is very weired scenario where User login and that log out to other users.

Next analysis

This error occurred while the current cookies not able to access the ELB – the cookies name is AWSELB secondly can be an issue from an application where Application takes longer to respond that the configured idle timeout.

When these cookies got generated-

Sticky session feature (also known as session affinity), which enables the load balancer to bind a user's session to a specific instance. ... Elastic Load Balancing creates a cookie, named AWSELB, that is used to map the session to the instance.

The second point we should review any recent change for the sickly session or in elastic load balancing related to cookies or session.

Solution 1: For application side – Dedicated QA team to reproduce this issue and review through fiddler 504 errors, then remove the cookies and try again to find out the pattern, this may not be a simple exercise so we should first consider/review

Solution 2: For server side - Monitor the HTTPCode_ELB_5XX and Latency metrics. If there is an increase in these metrics, it could be due to the application not responding within the idle timeout period. For details about the requests that are timing out, enable access logs on the load balancer and review the 504 response codes in the logs that are generated by Elastic Load Balancing. If necessary, you can increase your capacity or increase the configured idle timeout so that lengthy operations (such as uploading a large file) can complete. For more information, see Configure the Idle Connection Timeout for Your Classic Load Balancer and How do I troubleshoot Elastic Load Balancing high latency.

What could be a reason:-

1. This could be issue in some with AWSELB settings:- https://forums.aws.amazon.com/thread.jspa?threadID=153124

The issue was related to the way that Elastic Beanstalk EC2 servers are performing Log Rotation. The EC2 servers put an Apache proxy in front of Tomcat. Every hour, the EC2 instance rotates the apache logs and does a hard restart of the apache server. When this hard restart happens, it closes ALL existing connections to the httpd server and results in the 504 errors back to the ELB.

2. Why Sitecore captured these logs and understanding.

The error you are getting is quite self-explanatory. Your code tries to add/modify cookies after the response is set.

For a same time we have captured below logs from the application.

C:\Users\jitendra.so\Desktop\ReviewLogs\CommonLog.log20170831.11.txt (1 hit)

Line 960: 2017-08-31 11:24:00 Req:3dee3744-97c5-4 Host:MUIWSTAGSIT01 Url:/ SID: default\Anonymous 52708 ERROR in : Methods.cs method: SetCookie ,LineNumber 3526 : Exception Occured in Creating Cookie System.Web.HttpException (0x80004005): Server cannot modify cookies after HTTP headers have been sent.

C:\Users\jitendra.so\Desktop\ReviewLogs\CommonLog.log20170831.11.txt.2 (2 hits)

Line 189: 2017-08-31 11:23:58 Req:6e4881b1-2e92-4 Host:MUIWSTAGSIT01 Url:/ SID: default\Anonymous 31324 ERROR in : Methods.cs method: SetCookie ,LineNumber 3526 : Exception Occured in Creating Cookie System.Web.HttpException (0x80004005): Server cannot modify cookies after HTTP headers have been sent.

Line 514: 2017-08-31 11:23:59 Req:3dee3744-97c5-4 Host:MUIWSTAGSIT01 Url:/ SID: default\Anonymous 52708 ERROR in : Methods.cs method: SetCookie ,LineNumber 3526 : Exception Occured in Creating Cookie System.Web.HttpException (0x80004005): Server cannot modify cookies after HTTP headers have been sent.

C:\Users\jitendra.so\Desktop\ReviewLogs\CommonLog.log20170831.11.txt.4 (1 hit)

Line 209: 2017-08-31 11:23:57 Req:6e4881b1-2e92-4 Host:MUIWSTAGSIT01 Url:/ SID: default\Anonymous 31324 ERROR in : Methods.cs method: SetCookie ,LineNumber 3526 : Exception Occured in Creating Cookie System.Web.HttpException (0x80004005): Server cannot modify cookies after HTTP headers have been sent.

C:\Users\jitendra.so\Desktop\ReviewLogs\CommonLog.log20170831.11.txt.5 (1 hit)

Line 3079: 2017-08-31 11:22:30 Req:58b2c671-cb70-4 Host:MUIWSTAGSIT01 Url:/ SID: default\Anonymous 42228 ERROR in : Methods.cs method: SetCookie ,LineNumber 3526 : Ex

Sitecore XM Cloud, Ordercloud, CDP, Personalize, ContentHub and Send

Thursday, August 31, 2017

Sitecore and AWS - 504 Indepth review and resolution.

No comments:

Post a Comment