.NET Forum / .NET Framework / XML / August 2007
Input caching within Global.asax
|
|
Thread rating:  |
doug - 06 Aug 2007 14:54 GMT Not sure if this is better put heree or in some IIS6 NG.
I have put input caching into my global.asax file. Code listing below. I put a file dependency on the cache.
My issues is, my log file gets an entry when Application_Start gets triggered and writes an entry for 'FillCache invoked".
Eventually The file is updated vis FTP and the RefreshCache gets invoked and creates a log entry of "RefreshCache invoked" at 22:35. RefreshCache invokes FillCache but the log entry for "FillCache invoked" has a timestamp of 0400.
Can anyone shed some light the delayed call?
I do know IIS6 has default entries/settings for app pool and such.
**** Public Shared _cache As Cache = Nothing
Sub Application_Start _cache = Context.Cache Call Fill_Cache()
Private Sub FillCache()
Dim xmlDoc As New System.Xml.XmlDocument Dim xmlFile As String = "c:\temp\mydoc.xml"
xmlDoc.Load(xmlFile)
_cache.Insert("xmlDoc", xmlDoc, New CacheDependency(xmlFile), Cache.NoAbsoluteExpiration, Cache.NoSlidingExpiration, CacheItemPriority.Default, New CacheItemRemovedCallback(AddressOf RefreshCache))
Call logIt(enLogLevel.StartStopService, msLogFilePath, mcModule, "", "FillCache invoked")
End Sub
Private Sub RefreshCache(ByVal Key As String, ByVal Item As Object, ByVal Reason As CacheItemRemovedReason)
Call FillCache()
Call logIt(enLogLevel.StartStopService, msLogFilePath, mcModule, "", "RefreshCache invoked")
End Sub
WenYuan Wang [MSFT] - 07 Aug 2007 09:31 GMT Hello Doug,
It seems like an asp.net issue. According to your description, I understand you insert "mydoc.xml" document into cache and added Cachedependence to "mydoc.xml" file. Each time the file "mydoc.xml" modified, asp.net will clear the cache and load the file "mydoc.xml" again. Please correct me if I misunderstood anything here. Thanks.
But I'm not sure I have understood your issue very clearly. Would you please clarify the following thing for me? 1)
>RefreshCache invokes FillCache but the log entry for "FillCache invoked" has a timestamp of 0400.
Does "timestamp of 0400" mean 04:00 AM?
2) According to the code snippet you post in newsgroup, when "mydoc.xml" file modified, asp.net will clear cache and call RefreshCache method.
Private Sub RefreshCache) a)Call FillCache() b)Call logIt("RefreshCache invoked") End Sub
RefreshCache method will call FillCache() method first, and then call logIt("RefreshCache invoked").
Therefore, the entry for "FillCache invoked" should be logged before the entry for "RefreshCache invoked" in log file. such as FillCache invoked 22:35 RefreshCach invoked 22:35
However, according to your description, it seems these two entries are in wrong order. The entry for "FillCache" is below the entry "RefreshCache" in log file. Does I misunderstand anything here? such as RefreshCache invoked 22:35 FillCache invoked 0400
>Eventually The file is updated vis FTP and the RefreshCache gets invoked and >creates a log entry of "RefreshCache invoked" at 22:35. RefreshCache invokes >FillCache but the log entry for "FillCache invoked" has a timestamp of 0400. As far as I know, IIS 6.0 will shutdown asp.net processes after being idle for 20 minutes (default), recycle worker processes after 1740 minutes (default). If the "timestamp of 0400" means 04:00 am, I suspect this entry of "FullCache invoked" is logged when application restart.
Again, in order to figure out the root cause of issue quickly, please let me know 1) Does "timestamp of 0400" means "04:00 am"? 2) Would you please paste your log file in newsgroup? This helps on research very much. 3) Would you please paste the code snippet about logIt() method? We should check if you have closed the log file timely. Otherwise, the new entry will be lost when worker process restart.
I'm look forward to your reply. If you have any more concern on this, please feel free to let me know. I'm glad to assist you. Have a great day, Best regards, Wen Yuan Microsoft Online Community Support ================================================== This posting is provided "AS IS" with no warranties, and confers no rights.
doug - 08 Aug 2007 15:08 GMT I modified the code to log 1st then do calls so that it should log" hh:mm:ss RefreshCache_M involed! hh:mm:ss FillCache_M invoked! and I waited. This morning I see RefreshCache_M invoked at 17:50 CT and FillCache_M invoked at 19:44.
However I'll watch it another day or so to see more of a pattern.
doug
Private Sub FillCache_M()
Dim xmlDoc_M As New System.Xml.XmlDocument
Call logIt(enLogLevel.StartStopService, msLogFilePath, mcModule, "", "FillCache_C invoked")
mxmlDepositRatesDoc_C.Load(xmlDOC.xml)
_cache.Insert("xmlDoc_C", xmlDoc_M, New CacheDependency(xmlDox.xml), Cache.NoAbsoluteExpiration, Cache.NoSlidingExpiration, CacheItemPriority.Default, New CacheItemRemovedCallback(AddressOf RefreshCache_M))
End Sub
Private Sub RefreshCache_M(ByVal Key As String, ByVal Item As Object, ByVal Reason As CacheItemRemovedReason)
Call logIt(enLogLevel.StartStopService, msLogFilePath, mcModule, "", "RefreshCache_M invoked")
Call FillCache_M()
End Sub
> Hello Doug, > [quoted text clipped - 68 lines] > ================================================== > This posting is provided "AS IS" with no warranties, and confers no rights. WenYuan Wang [MSFT] - 09 Aug 2007 12:24 GMT Hello Doug,
I have tried your code on my side.
I created an ASP.net 2.0 Website project, added default.aspx page. In default.aspx.cs file, I defined FillCache_M(), LogIt(), and RefreshCache_M() methods. LogIt() method open the log.txt file and append current time into log file.
In Page_Load event, FillCach_M() method was called to load xml file. protected void Page_Load(object sender, EventArgs e) { FillCach_M(); }
After asp.net running, I edited the xml file and checked log file 2007/8/9 18:52:02FillCache 2007/8/9 18:52:13RefreshCache_M invoked 2007/8/9 18:52:13FillCache
It seems works fine. I'm not sure if I repro the issue in the same way as yours. Please let me know if I'm missing anything here. I will check it again. thanks.
At last, I suggest you may add a entry for "END RefreshCache_M invoked". This line of code could help us to check whether the refresh method finished on time.
Private Sub RefreshCache_M(ByVal Key As String, ByVal Item As Object, ByVal Reason As CacheItemRemovedReason)
Call logIt(enLogLevel.StartStopService, msLogFilePath, mcModule, "", "RefreshCache_M invoked")
Call FillCache_M()
* Call logIt(enLogLevel.StartStopService, msLogFilePath, mcModule, "", "End RefreshCache_M invoked")
End Sub
Hope this helps. Best regards, Wen Yuan Microsoft Online Community Support ================================================== This posting is provided "AS IS" with no warranties, and confers no rights.
doug - 13 Aug 2007 14:56 GMT My appologies. Was in class all last week. Most of this week too.
I have not seen the behavior since my first post, but I've not seen each days log either.
I will add the suggesed end routine log.
I added a logit to Application_Error and it is being tripped whenever the FillCache_M is invoked after the RefreshCache_M gets invoked. This may be normal, I'm not sure. My understanding is several things now cause web site to be cycled which would invoke application_start.
I'm seeing:
Application_Start Invoked FillCache_M Invoked
RefreshCache_M Invoked FillCache_M Invoked
Application_Error Invoked
Application_Start Invoked . . .
This cycle repeats 2 - 3 times a day.
doug
> Hello Doug, > [quoted text clipped - 44 lines] > ================================================== > This posting is provided "AS IS" with no warranties, and confers no rights. doug - 13 Aug 2007 15:06 GMT I reread this and it seemed I left the impression the Application_Starts were somehow tightly associated with the Application_Error. This is not the case. This is a special website not always used. Currently is hosts mostly ASP web content, with this new ASp.Net ASMX being the first .Net code installed. I'm guessing the "app" gets started, dies thru inactivity (which may trigger the Application_Error?), yet causes the cache to be refreshed.
> My appologies. Was in class all last week. Most of this week too. > [quoted text clipped - 75 lines] > > ================================================== > > This posting is provided "AS IS" with no warranties, and confers no rights. WenYuan Wang [MSFT] - 14 Aug 2007 12:14 GMT Hello Doug Thanks for your reply.
I afraid this is not a normal behavior. In fact, application doesn't restart each time there is an unhandled exception.
Scott wrote a blog about the method how to log the reason why web application restart. I suggest we may consider logging the Application_End event . Therefore we could figure out the root cause of restarting application. http://weblogs.asp.net/scottgu/archive/2005/12/14/433194.aspx [Logging ASP.NET Application Shutdown Events]
Please let me know if there is anything we can help with. We are glad to assist you. Have a great day, Best regards, Wen Yuan Microsoft Online Community Support ================================================== This posting is provided "AS IS" with no warranties, and confers no rights.
doug - 17 Aug 2007 17:02 GMT Here is the flow, in a stable, unused ASP3 website that has this single ASP.Net WebService and log reporting aspx pages: 00:45 Application_Start Invokes 00:45 FillCache_M Invoked 01:06 RefreshCache_M Invoked 01:06 FillCache_M Invoked 01:06 Application_Error Invoked 01:06 Application_End Invoked now I request LogReport.aspx to display log file 10:52 Application_Start Invoked 10:52 FillChache_M Invoked
I will read the app error blog link now.
> Hello Doug > Thanks for your reply. [quoted text clipped - 17 lines] > ================================================== > This posting is provided "AS IS" with no warranties, and confers no rights. doug - 17 Aug 2007 22:53 GMT I added the code for trapping the application ending reason from the hyperlink you provided to my application_end routine. Application_End is called after Application_Error. Here is what I logged: Application_End: _shutDownMessage=HostingEnvironment caused shutdown _shutDownStack= at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo) at System.Environment.get_StackTrace() at System.Web.HttpRuntime.ShutdownAppDomain() at System.Web.Hosting.HostingEnvironment.ShutdownThisAppDomainOnce() at System.Web.Hosting.HostingEnvironment.InitiateShutdownWorkItemCallback(Object state) at System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(Object state) at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state) at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(Object state) ShutdownReason=HostingEnvironment
> Not sure if this is better put heree or in some IIS6 NG. > [quoted text clipped - 45 lines] > > End Sub WenYuan Wang [MSFT] - 20 Aug 2007 13:44 GMT Hello Doug, Thanks for your reply,
In IIS 6.0, long time inactivity does not trigger the Application_Error event. I think the reason of restaring application is that it failed to execute FillCache_M method. Thereby, Application_Error was called and then Application_End was invoked.
Is there any exception in Application_Error event? Have you logged Error message in Application Error? If not, please paste the following code snippet in Application_Error event. Therefore we could capture the detailed information about Error.
I apologize for asking for some much information. According to your description, the issue doesn't occur each time after RefreshCache.(only 2-3 time each day). It's not possible for use to reproduce the issue on our side. Thus, we need enough information to analysis.
void Application_Error(object sender, EventArgs e) { Exception ex = Server.GetLastError(); string sLogMsg = null; try { // You do not need to log the HttpUnhandledException that // ASP.NET wrapped the exception in. if ((ex as System.Web.HttpUnhandledException) != null) ex = ex.InnerException;
// Format message for the main exception. sLogMsg = string.Format("Unhandled exception. Type={0} Msg={1}\nStackTrace=\n{2}", ex.GetType().FullName, ex.Message, ex.StackTrace);
// Format the message for any inner exceptions. while ((ex = ex.InnerException) != null) { sLogMsg += string.Format("\n\nInner exception. Type={0} Msg={1}", ex.GetType().FullName, ex.Message); System.Runtime.InteropServices.COMException ce = ex as System.Runtime.InteropServices.COMException; if (ce != null) sLogMsg += "\nCOM Exception errcode = " + ce.ErrorCode.ToString(); } } catch { } finally { // Log the event to the event log. if (!System.Diagnostics.EventLog.SourceExists(".NET Runtime")) { System.Diagnostics.EventLog.CreateEventSource(".NET Runtime", "Application"); } System.Diagnostics.EventLog log = new System.Diagnostics.EventLog(); log.Source = ".NET Runtime"; log.WriteEntry(sLogMsg, System.Diagnostics.EventLogEntryType.Error); } }
Please try the above method and check the event log. Let me know if there is updated information.I'm stading by. Have a great day.
Best regards, Wen Yuan Microsoft Online Community Support ================================================== This posting is provided "AS IS" with no warranties, and confers no rights.
doug - 20 Aug 2007 19:02 GMT I tried converting this to VB till I figured out the 'ex as .....' which converts value to null on conversion error rather than raising exception. Rather than test my conversion skills that might get this wrong, could you please provide routine in VB.Net?
Much appreciated.
doug
> Hello Doug, > Thanks for your reply, [quoted text clipped - 72 lines] > ================================================== > This posting is provided "AS IS" with no warranties, and confers no rights. WenYuan Wang [MSFT] - 21 Aug 2007 06:11 GMT Hello Doug Thanks for your reply.
Have you tried with TryCast()? This method will return Nothing on Conversion error. http://msdn2.microsoft.com/en-us/library/zyy863x8(VS.80).aspx
Dim ce As System.Runtime.InteropServices.COMException = TryCast(ex, System.Runtime.InteropServices.COMException) If (ce IsNot Nothing) Then sLogMsg += "\nCOM Exception errcode = " + ce.ErrorCode.ToString() End If
Hope this helps. If you have any further issue, please feel free to let me know. I'm glad to assist you.
Best regards, Wen Yuan Microsoft Online Community Support ================================================== This posting is provided "AS IS" with no warranties, and confers no rights.
doug - 21 Aug 2007 16:56 GMT Here is what was posted to Application_Error routine: Unhandled exception. Type=System.Web.HttpException Msg=Server operation is not available in this context.\nStackTrace=\n at System.Web.HttpServerUtility.MapPath(String path) at GlobalAsax.FillCache_M() at GlobalAsax.RefreshCache_M(String Key, Object Item, CacheItemRemovedReason Reason) at System.Web.Caching.CacheEntry.CallCacheItemRemovedCallback(CacheItemRemovedCallback callback, CacheItemRemovedReason reason)
Looks like MapPath went out of scope?
doug
> Hello Doug > Thanks for your reply. [quoted text clipped - 18 lines] > ================================================== > This posting is provided "AS IS" with no warranties, and confers no rights. doug - 21 Aug 2007 17:10 GMT This is the code in the FillCache_M routine: gsXMLSrcFilePath_M = ConfigurationManager.AppSettings("XMLSrcFilePath_M") If gsXMLSrcFilePath_M Is Nothing Then gsXMLSrcFilePath_M = "Extract_Model.xml" End If gsXMLSrcFilePath_M = Server.MapPath(gsXMLSrcFilePath_M)
> Here is what was posted to Application_Error routine: > Unhandled exception. Type=System.Web.HttpException Msg=Server operation is [quoted text clipped - 30 lines] > > ================================================== > > This posting is provided "AS IS" with no warranties, and confers no rights. WenYuan Wang [MSFT] - 22 Aug 2007 14:31 GMT Hello Doug, Thanks for your reply.
I did trouble shoot the whole day and figured out the root case.
The Server.MapPath call use the following code to return the correct path context.Request.MapPath(path);
The context object is not available because this object is only available when ASPNET process an ASPX page. When the page an ASPX page is unloaded, the context object is deleted.
In your case, this website is not always used. The aspx page will be unloaded if there is no request for long time. So, there is no context object when GlobalAsax.RefreshCache_M calls MapPath().
"Server operation is not available in this context." exception was thrown.
To resolve this issue, I suggest you write the absolute file path in Web.config file, rather than call MapPath() method in FillCach_M method.
Would you please try this method and let me know if this resolves the issue. I'm glad to assist you. Have a great day. Best regards,
Wen Yuan Microsoft Online Community Support ================================================== This posting is provided "AS IS" with no warranties, and confers no rights.
doug - 22 Aug 2007 15:02 GMT That certainly explains it. Thank you.
doug
> Hello Doug, > Thanks for your reply. [quoted text clipped - 26 lines] > ================================================== > This posting is provided "AS IS" with no warranties, and confers no rights. doug - 22 Aug 2007 17:16 GMT Replacing MapPath with physical path hard coded and the Application_error path did not get invoked.
> Hello Doug, > Thanks for your reply. [quoted text clipped - 26 lines] > ================================================== > This posting is provided "AS IS" with no warranties, and confers no rights. WenYuan Wang [MSFT] - 23 Aug 2007 08:56 GMT Hello Doug, Thanks for your reply.
It seems the issue has gone away now. Anyway, I'm standing by. Let me know if you notice the issue occurs again. We are glad to assist you. Have a great day,
Best regards, Wen Yuan Microsoft Online Community Support ================================================== This posting is provided "AS IS" with no warranties, and confers no rights.
Free MagazinesGet these publications absolutely FREE for up to 12 months. There are no hidden fees and no obligation. Simply choose a title, complete the application form and submit it. Read more ...
|
|
|