Andrew Arnott | 27 Nov 20:35 2011
Picon

ThreadLogicalContext not actually following logical threads

I'm trying to use log4net.LogicalThreadContext.Stacks[stackName].Push(value) to push context onto the logical thread.  But I can see that ThreadPool.QueueUserWorkItem, and other ways that the .NET CallContext is propagated do not actually receive the log4net.LogicalThreadContext, and as a result these other threads don't have any stack inherited from the context that spawned it.

I am successfully using CallContext.LogicalSetData myself for other logical thread tracking purposes in my application so I have reason to believe it works -- I just don't know why log4net isn't working.  Any ideas?

Thanks.

--
Andrew Arnott
"I [may] not agree with what you have to say, but I'll defend to the death your right to say it." - S. G. Tallentyre

Stefan Bodewig | 28 Nov 17:52 2011
Picon

Re: ThreadLogicalContext not actually following logical threads

On 2011-11-27, Andrew Arnott wrote:

> I am successfully using CallContext.LogicalSetData myself for other logical
> thread tracking purposes in my application so I have reason to believe it
> works -- I just don't know why log4net isn't working.  Any ideas?

LogicalThreadContext uses SetData rather than LogicalSetData (the latter
isn't available in .NET 1.x).  Based on no knowledge other than MSDN it
is unclear to me what SetData would do if it didn't work on the logical
thread, but there probably is a reason for having two methods.

Stefan

Andrew Arnott | 28 Nov 18:35 2011
Picon

Re: ThreadLogicalContext not actually following logical threads

The documentation is poor, I agree.  I had to stumble around quite a bit before I figured out how to use it properly myself.  I believe the difference may be that CallContext.LogicalSetData requires the value to be serializable, so that it can be cloned and applied to other threads, perhaps even in separate appdomains.
 
This sounds like an area that log4net can improve then.  I'm not sure why log4net claims to follow the logical thread when apparently it doesn't.
 
The good news is that in the absence of built-in support from log4net, I've engineered a solution of my own by controlling the HostExecutionContextManager in my AppDomain.  Whenever the logical thread forks (i.e. threadpool use, c# 5 async keyword, etc.) my code "captures" the current context stack from log4net and applies that stack to the new thread, and "reverts" that change when the target thread has completed its work for that call.
 
Pretty cool stuff, but it would be cooler if log4net had it built-in.
--
Andrew Arnott
"I [may] not agree with what you have to say, but I'll defend to the death your right to say it." - S. G. Tallentyre


On Mon, Nov 28, 2011 at 8:52 AM, Stefan Bodewig <bodewig <at> apache.org> wrote:
On 2011-11-27, Andrew Arnott wrote:

> I am successfully using CallContext.LogicalSetData myself for other logical
> thread tracking purposes in my application so I have reason to believe it
> works -- I just don't know why log4net isn't working.  Any ideas?

LogicalThreadContext uses SetData rather than LogicalSetData (the latter
isn't available in .NET 1.x).  Based on no knowledge other than MSDN it
is unclear to me what SetData would do if it didn't work on the logical
thread, but there probably is a reason for having two methods.

Stefan

Stefan Bodewig | 29 Nov 06:13 2011
Picon

Re: ThreadLogicalContext not actually following logical threads

On 2011-11-28, Andrew Arnott wrote:

> The documentation is poor, I agree.  I had to stumble around quite a bit
> before I figured out how to use it properly myself.  I believe the
> difference may be that CallContext.*Logical*SetData requires the value to
> be serializable, so that it can be cloned and applied to other threads,
> perhaps even in separate appdomains.

> This sounds like an area that log4net can improve then.

For .NET 2+, yes.

> I'm not sure why log4net claims to follow the logical thread when
> apparently it doesn't.

It probably does in some circumstances but obviously not all of them.

> The good news is that in the absence of built-in support from log4net, I've
> engineered a solution of my own by controlling the
> HostExecutionContextManager in my AppDomain.  Whenever the logical thread
> forks (i.e. threadpool use, c# 5 async keyword, etc.) my code "captures"
> the current context stack from log4net and applies that stack to the new
> thread, and "reverts" that change when the target thread has completed its
> work for that call.

> Pretty cool stuff, but it would be cooler if log4net had it built-in.

Oh, feel free to help log4net improve here 8-)

Cheers

        Stefan

Andrew Arnott | 29 Nov 17:10 2011
Picon

Re: ThreadLogicalContext not actually following logical threads

I'd be happy to help.  But given the fact that I'm a Microsoft employee with some strict open source restrictions, I can only provide support for it.  


In short, if log4net stores its logical call-tracking context stack using CallContext.LogicalSetData and retrieves it using the similarly named method, everything should automatically work.  If not, I can hopefully provide additional help.

--
Andrew Arnott
"I [may] not agree with what you have to say, but I'll defend to the death your right to say it." - S. G. Tallentyre


On Mon, Nov 28, 2011 at 9:13 PM, Stefan Bodewig <bodewig <at> apache.org> wrote:
On 2011-11-28, Andrew Arnott wrote:

> The documentation is poor, I agree.  I had to stumble around quite a bit
> before I figured out how to use it properly myself.  I believe the
> difference may be that CallContext.*Logical*SetData requires the value to
> be serializable, so that it can be cloned and applied to other threads,
> perhaps even in separate appdomains.

> This sounds like an area that log4net can improve then.

For .NET 2+, yes.

> I'm not sure why log4net claims to follow the logical thread when
> apparently it doesn't.

It probably does in some circumstances but obviously not all of them.

> The good news is that in the absence of built-in support from log4net, I've
> engineered a solution of my own by controlling the
> HostExecutionContextManager in my AppDomain.  Whenever the logical thread
> forks (i.e. threadpool use, c# 5 async keyword, etc.) my code "captures"
> the current context stack from log4net and applies that stack to the new
> thread, and "reverts" that change when the target thread has completed its
> work for that call.

> Pretty cool stuff, but it would be cooler if log4net had it built-in.

Oh, feel free to help log4net improve here 8-)

Cheers

       Stefan

Stefan Bodewig | 29 Nov 17:22 2011
Picon

Re: ThreadLogicalContext not actually following logical threads

On 2011-11-29, Andrew Arnott wrote:

> I'd be happy to help.  But given the fact that I'm a Microsoft employee
> with some strict open source restrictions, I can only provide support for
> it.

OK, understood.  And thank you for your support.

> In short, if log4net stores its logical call-tracking context stack
> using CallContext.LogicalSetData and retrieves it using the similarly
> named method, everything should automatically work.  If not, I can
> hopefully provide additional help.

https://issues.apache.org/jira/browse/LOG4NET-317

and should be fixed pretty soon.

Thanks

        Stefan

Andrew Arnott | 12 Dec 05:33 2011
Picon

Re: ThreadLogicalContext not actually following logical threads

Thanks for fixing this, Stefan.  I haven't looked at your checkin itself (r1207948 apparently), but just a heads up, that unless you're using an immutable stack, you may want to verify that the stack doesn't corrupt itself from threads with different contexts modifying the same object.  I'm not sure whether the objects automatically get serialized or not--if not, then you probably need to use an immutable stack.
--
Andrew Arnott
"I [may] not agree with what you have to say, but I'll defend to the death your right to say it." - S. G. Tallentyre


On Tue, Nov 29, 2011 at 8:22 AM, Stefan Bodewig <bodewig <at> apache.org> wrote:
On 2011-11-29, Andrew Arnott wrote:

> I'd be happy to help.  But given the fact that I'm a Microsoft employee
> with some strict open source restrictions, I can only provide support for
> it.

OK, understood.  And thank you for your support.

> In short, if log4net stores its logical call-tracking context stack
> using CallContext.LogicalSetData and retrieves it using the similarly
> named method, everything should automatically work.  If not, I can
> hopefully provide additional help.

https://issues.apache.org/jira/browse/LOG4NET-317

and should be fixed pretty soon.

Thanks

       Stefan


Gmane