[jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-07 Thread Husain Alshehhi (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15960776#comment-15960776
 ] 

Husain Alshehhi commented on LOG4NET-562:
-

[~ahouben] You are right. I posted the problem here: 
https://github.com/dotnet/corefx/issues/17968#issuecomment-292198196. The 
summary is that parallel actually reuses the thread without clearing the 
threadcontext.

> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL: https://issues.apache.org/jira/browse/LOG4NET-562
> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10, Visual Studio 17, .NET Framework 4.5.2
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)


[jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-07 Thread Alexander Houben (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15960517#comment-15960517
 ] 

Alexander Houben commented on LOG4NET-562:
--

Hello Husain,

I think the observed behavior lies in the implementation of Parallel.ForEach. 
All your assumptions seem correct to me except that Parallel.ForEach does not 
execute its actions on a separate thread or separate task each.

If you look at mscorlib with ILSpy and find 
System.Threading.Tasks.Parallel.ForEach you'll see that it does some heavy 
optimization to find the right ratio of threads/tasks and load.

IMHO it may be reusing a task where your "x-correlation-id" was set (if (i==3)) 
for other values of i, this is why you are seeing multiple modified log outputs.

cheers,
alex

> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL: https://issues.apache.org/jira/browse/LOG4NET-562
> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10, Visual Studio 17, .NET Framework 4.5.2
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", 

Re: [jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-07 Thread Dominik Psenner
Thanks Alexander, that's exactly what I was suspecting. 
Parallel.ForEach() may not necessarily be using different threads to 
execute the tasks. Also, the latest stuff that can be implemented with 
async/await levers high parallelism without the need of multithreading. 
Only I'm afraid you have to post this on JIRA as well because Husain is 
probably not subscribed to the mailing list.



On 2017-04-07 10:31, Alexander Houben wrote:

Hello Husain,

I think the observed behavior lies in the implementation of 
Parallel.ForEach. All your assumptions seem correct to me except that 
Parallel.ForEach does not execute its actions on a separate thread or 
separate task each.


If you look at mscorlib with ILSpy and find 
System.Threading.Tasks.Parallel.ForEach you'll see that it does some 
heavy optimization to find the right ratio of threads/tasks and load.


IMHO it may be reusing a task where your "x-correlation-id" was set 
(if (i==3)) for other values of i, this is why you are seeing multiple 
modified log outputs.


cheers,
alex

On Fri, Apr 7, 2017 at 10:04 AM, Dominik Psenner (JIRA) 
mailto:[email protected]>> wrote:



[

https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15960445#comment-15960445


]

Dominik Psenner commented on LOG4NET-562:
-

Have you tried to include the actual thread that the code executes
in by logging System.Threading.Thread.CurrentThread.ManagedThreadId?

> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL:
https://issues.apache.org/jira/browse/LOG4NET-562

> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10, Visual Studio 17, .NET
Framework 4.5.2
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they
shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"]
= "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
>   
 LogicalThreadContext.Properties["x-corralation-Id"] =

"modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO",
"x-corralation-Id" : "original-value", "logger":"logger",
"message":"thread 1.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO",
"x-corralation-Id" : "modified-value", "logger":"logger",
"message":"thread 3.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
"x-corralation-Id" : "modified-value", "logger":"logger",
"message":"thread 4.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
"x-corralation-Id" : "modified-value", "logger":"logger",
"message":"thread 6.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO",
"x-corralation-Id" : "modified-value", "logger":"logger",
"message":"thread 8.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO",
"x-corralation-Id" : "modified-value", "logger":"logger",
"message":"thread 0.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO",
"x-corralation-Id" : "original-value", "logger":"logger",
"message":"thread 7.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO",
"x-corralation-Id" : "original-value", "logger":"logger",
"message":"thread 5.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
"x-corralation-Id" : "original-value", "logger":"logger",
"message":"thread 2.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO",
"x-corralation-Id" : "original-value", "logger":"logger",
"message":"thread 9.", "data":(null)}
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO",
"x-corralation-Id" : "original-value", "logger":"logger",
"message":"thread 1.", "data":(null)}
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO",
"x-corralation-Id" : 

Re: [jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-07 Thread Alexander Houben
Hello Husain,

I think the observed behavior lies in the implementation of
Parallel.ForEach. All your assumptions seem correct to me except that
Parallel.ForEach does not execute its actions on a separate thread or
separate task each.

If you look at mscorlib with ILSpy and find
System.Threading.Tasks.Parallel.ForEach you'll see that it does some heavy
optimization to find the right ratio of threads/tasks and load.

IMHO it may be reusing a task where your "x-correlation-id" was set (if
(i==3)) for other values of i, this is why you are seeing multiple modified
log outputs.

cheers,
alex

On Fri, Apr 7, 2017 at 10:04 AM, Dominik Psenner (JIRA) 
wrote:

>
> [ https://issues.apache.org/jira/browse/LOG4NET-562?page=
> com.atlassian.jira.plugin.system.issuetabpanels:comment-
> tabpanel&focusedCommentId=15960445#comment-15960445 ]
>
> Dominik Psenner commented on LOG4NET-562:
> -
>
> Have you tried to include the actual thread that the code executes in by
> logging System.Threading.Thread.CurrentThread.ManagedThreadId?
>
> > LogicalThreadContext is not per Thread
> > --
> >
> > Key: LOG4NET-562
> > URL: https://issues.apache.org/jira/browse/LOG4NET-562
> > Project: Log4net
> >  Issue Type: Bug
> >  Components: Other
> >Affects Versions: 2.0.8
> > Environment: Windows 10, Visual Studio 17, .NET Framework 4.5.2
> >Reporter: Husain Alshehhi
> >
> > LogicalThreadContext values are spread to many threads when they
> shouldn't.
> > This is an example:
> > {code:title=console.cs|borderStyle=solid}
> > LogicalThreadContext.Properties["x-corralation-Id"] =
> "original-value";
> > var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> > Parallel.ForEach(list, (i) =>
> > {
> > if (i == 3)
> > LogicalThreadContext.Properties["x-corralation-Id"]
> = "modified-value";
> > logger.Info($"thread {i}.");
> > });
> > {code}
> > this is the result
> > {code:title=badresult.txt|borderStyle=solid}
> > {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 1.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO",
> "x-corralation-Id" : "modified-value", "logger":"logger", "message":"thread
> 3.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
> "x-corralation-Id" : "modified-value", "logger":"logger", "message":"thread
> 4.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
> "x-corralation-Id" : "modified-value", "logger":"logger", "message":"thread
> 6.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO",
> "x-corralation-Id" : "modified-value", "logger":"logger", "message":"thread
> 8.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO",
> "x-corralation-Id" : "modified-value", "logger":"logger", "message":"thread
> 0.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 7.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 5.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 2.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 9.", "data":(null)}
> > {code}
> > This is what I was expecting:
> > {code:title=goodresult.txt|borderStyle=solid}
> > {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 1.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO",
> "x-corralation-Id" : "modified-value", "logger":"logger", "message":"thread
> 3.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 4.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 6.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 8.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 0.", "data":(null)}
> > {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO",
> "x-corralation-Id" : "original-value", "logger":"logger", "message":"thread
> 7.", 

[jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-07 Thread Dominik Psenner (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15960445#comment-15960445
 ] 

Dominik Psenner commented on LOG4NET-562:
-

Have you tried to include the actual thread that the code executes in by 
logging System.Threading.Thread.CurrentThread.ManagedThreadId?

> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL: https://issues.apache.org/jira/browse/LOG4NET-562
> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10, Visual Studio 17, .NET Framework 4.5.2
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)


[jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-06 Thread Husain Alshehhi (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15958808#comment-15958808
 ] 

Husain Alshehhi commented on LOG4NET-562:
-

[~nachbarslumpi] Correct. The value can travel from one thread to another, but 
it should not travel to any thread arbitrarily. 

When I configure a particular thread context to be a certain value, that should 
not affect its neighbor threads. It should only affect its children threads. In 
the example I gave, I changes the main thread context, which should carry on to 
all child threads, and when I change a particular child thread context, that 
should not affect any other children's context.

I started to see this problem when I use Parrallel API. I am suprised that when 
I use Task API with WaitAll, the code outputs as expected.


> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL: https://issues.apache.org/jira/browse/LOG4NET-562
> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10, Visual Studio 17, .NET Framework 4.5.2
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> 

[jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-06 Thread Dominik Psenner (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15958776#comment-15958776
 ] 

Dominik Psenner commented on LOG4NET-562:
-

To me this works as designed. The LogicalThreadContext is not intended to be 
unique for each thread. It is a "logical thread context", which may travel from 
one thread to another.

> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL: https://issues.apache.org/jira/browse/LOG4NET-562
> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10, Visual Studio 17, .NET Framework 4.5.2
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)


[jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-06 Thread Husain Alshehhi (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15958769#comment-15958769
 ] 

Husain Alshehhi commented on LOG4NET-562:
-

[~twcclegg] I updated the issue to reflect the problem. It is 4.5.2 on visual 
studio 17. (Sorry, VS 16 was a typo. Microsoft is crazy with their versioning 
number.)

> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL: https://issues.apache.org/jira/browse/LOG4NET-562
> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10, Visual Studio 17, .NET Framework 4.5.2
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)


[jira] [Commented] (LOG4NET-562) LogicalThreadContext is not per Thread

2017-04-05 Thread Thomas Clegg (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4NET-562?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15957243#comment-15957243
 ] 

Thomas Clegg commented on LOG4NET-562:
--

Can you provide the version of .NET you are using? Also VS 16?

> LogicalThreadContext is not per Thread
> --
>
> Key: LOG4NET-562
> URL: https://issues.apache.org/jira/browse/LOG4NET-562
> Project: Log4net
>  Issue Type: Bug
>  Components: Other
>Affects Versions: 2.0.8
> Environment: Windows 10. VS 16.
>Reporter: Husain Alshehhi
>
> LogicalThreadContext values are spread to many threads when they shouldn't.
> This is an example:
> {code:title=console.cs|borderStyle=solid}
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "original-value";
> var list = new List {1, 2, 3, 4, 5, 6, 7, 8, 9, 0};
> Parallel.ForEach(list, (i) =>
> {
> if (i == 3)
> LogicalThreadContext.Properties["x-corralation-Id"] = 
> "modified-value";
> logger.Info($"thread {i}.");
> });
> {code}
> this is the result
> {code:title=badresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}
> This is what I was expecting:
> {code:title=goodresult.txt|borderStyle=solid}
> {"timestamp":"2017-04-05T12:31:41.117Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 1.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.132Z", "level":"INFO", "x-corralation-Id" : 
> "modified-value", "logger":"logger", "message":"thread 3.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 4.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 6.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 8.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.274Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 0.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.219Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 7.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.179Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 5.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.273Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 2.", "data":(null)} 
> {"timestamp":"2017-04-05T12:31:41.234Z", "level":"INFO", "x-corralation-Id" : 
> "original-value", "logger":"logger", "message":"thread 9.", "data":(null)} 
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)