Stack Exception when disposing of Trace

Topics: Logging Application Block
Feb 11, 2009 at 7:13 PM
Edited Feb 11, 2009 at 8:01 PM
It's entirely possible I'm getting this because my approach is wrong..
Info
-I'm running Ent Lib 4.1 on top of 3.5 SP1
-This is for a website (so it's multi threaded)
-in the "PreRequestHandlerExecute" I start a Trace and store it in the Context.Items collection
-in the "EndRequest" I retrieve this Trace from the Context.Items and Dispose of it (before I dispose of it though I make sure it exists and that "IsTracingEnabled")

I do it like this because I want all messages logged to be associated with this Tracer....
I'm using the Exception Handling App Block as well and it logs messages through the same Logging Block.....
So if exceptions occur and get logged they get associated with the tracer representing the scope of the request.

I've been trying to recreate this exception locally but I can't :(
It only happens on our staging/production servers.

I used the MS Web Stress tool to hit a local page with multiple threads and it still didn't cause the exception.
I'll keep trying to recreate it locally if I can.....

Here's the EXCEPTION

Type : System.InvalidOperationException, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089  
Message : Stack empty.  Source : mscorlib  Help link :   
Data : System.Collections.ListDictionaryInternal  TargetSite : System.Object Pop()  Stack Trace :    
at System.Collections.Stack.Pop()     
at System.Diagnostics.CorrelationManager.StopLogicalOperation()     
at Microsoft.Practices.EnterpriseLibrary.Logging.Tracer.Dispose(Boolean disposing)     
at Microsoft.Practices.EnterpriseLibrary.Logging.Tracer.Dispose()     
at WOGUtility.Logging.LoggingFacade.Dispose() in LoggingFacade.cs:line 100     
at WOG.Library.HttpModules.LoggingModule.context_EndRequest(Object sender, EventArgs e) in LoggingModule.cs:line 91     
at System.Web.HttpApplication.SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()     
at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)



Feb 12, 2009 at 2:06 AM
Let me know if your problem is something like this - http://www.codeplex.com/entlib/WorkItem/View.aspx?WorkItemId=9592


Sarah Urmeneta
Global Technology & Solutions
Avanade, Inc.
entlib.support@avanade.com
Feb 12, 2009 at 2:30 AM
Yea I meant to reference that :)


""This issue is fixed by the .NET 2.0 SP1, which includes the hotfix described in http://support.microsoft.com/kb/936233.
.NET 3.5 includes the .NET 2.0 SP1, so EntLib v4 shouldn't be affected."

I'm running 3.5 sp1 and entlib v4 so it seems like it's a different problem.

I only have the Logging block and Exception Block implemented....

it seems like something goes wrong when it places the trace on the stack.... Because The attempt to pop from the stack doesn't appear to have an associated push.
Like if I look at my logs I notice that at the point it's trying to dispose of the trace it never logged a "start trace" event     ...... But it seems to think that an active trace is present because it attempts to pop it off the stack..

Which I know is all very vague :( I still haven't been able to reproduce locally
Feb 12, 2009 at 3:14 AM
Just wanted to make sure first that you've already seen that issue before making any assumptions. Anyway, it would be hard to know exactly what is causing the error here, I'm also trying to repro your error.  I'll let you know what I can find out.


Sarah Urmeneta
Global Technology & Solutions
Avanade, Inc.
entlib.support@avanade.com
May 13, 2013 at 11:30 AM
Hi,
i would like to know if there's something new to this issue. I have the same behavior in a .net 4 Project with EntLib 5.0.505.0. My Code looks like this:
        using (var tracer = new Tracer(Category.ProcessItem.ToString()))
        {
            using (var context = new PortalContext())
            {
                    using (new Tracer(Category.DocumentsQuery.ToString()))
                {
                    // do sthg. in multiple threads and tasks...
                }

                try
                {
                    // do sthg. in multiple threads and tasks...
                }
                catch (Exception ex)
                {
                    // handle error
                }
            }
        // exception when disposing Tracer
        }
Thank you.
Jan
May 13, 2013 at 10:26 PM
I'm assuming you are getting an InvalidOperationException from CorrelationManager (or a call from CorrelationManager)? Internally, Tracer uses CorrelationManager.

There was an issue with CorrelationManager: http://connect.microsoft.com/VisualStudio/feedback/details/609929/logicalcallcontext-clone-bug-when-correlationmanager-slot-is-present. The comment on the site suggests that the issue is only fixed in .NET 4.5. Since you have a repro, I wonder if you could try running it against .NET 4.5 to see if this resolves your issue?

Another alternative might be to try some of the approaches documented here: http://stackoverflow.com/questions/4729479/is-correlationmanager-logicaloperationstack-compatible-with-parallel-for-tasks. However, it would probably be a bit of work if you wanted to integrate back with Enterprise Library.

~~
Randy Levy
entlib.support@live.com
Enterprise Library support engineer
Support How-to