You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4net-user@logging.apache.org by "Joseph.r" <ra...@gmail.com> on 2012/06/01 20:24:59 UTC

Log4Net logs incorrect data

I have a WCF service where in I use Log4Net for logging information to Sql
Server database. I use Log4Net's GlobalContext to log some extra
information, like Transaction Name, Status, Message, and few other stuff.
Some of the important transactions within this system are Read, Write and
Login.

The log should look like:

"Read" -------- "Success" -------- "Read xxx customer data"
"Write" -------- "Success" -------- "Written xxx customer's data"
"Login" -------- "Failure" -------- "User session already exists."
Everything works fine when I run my normal tests - the logs are written to
the database perfectly. However, recently I did a load test by using JMeter.
The above mentioned three transactions were tested in 100 concurrent threads
for 3 minutes. When I checked the DB logs, I found that some of the
information were logged incorrectly.

Ex:

"Read" -------- "Success" -------- "User session already exists."
"Write" -------- "Success" -------- "Read xxx customer data"
Is this an issue with Log4Net GlobalContext not being thread safe? I tried
using ThreadContext instead of GlobalContext, but looks like lots of
information were not logged.
-- 
View this message in context: http://old.nabble.com/Log4Net-logs-incorrect-data-tp33946524p33946524.html
Sent from the Log4net - Users mailing list archive at Nabble.com.


Re: Log4Net logs incorrect data

Posted by Ron Grabowski <ro...@yahoo.com>.
Add a custom converter to your PatternLayout:


 <layout type="log4net.Layout.PatternLayout">
  <converter>
    <name value="operationContext" />
    <type value="MyCompany.Logging.Layout.Pattern.OperationContextPatternConverter" />
   </converter>
  <conversionPattern value="%5level %date - %operationContext{Status} - %message%newline" />
 </layout>

Or extend PatternLayout if you're going to re-use the converter across multiple appenders:

 <layout type="MyCompany.Logging.Layout.PatternLayout">
  <conversionPattern value="%5level %date - %operationContext{Status} - %message%newline" />
 </layout>


________________________________
 From: Joseph.r <ra...@gmail.com>
To: log4net-user@logging.apache.org 
Sent: Saturday, June 2, 2012 9:20 PM
Subject: Re: Log4Net logs incorrect data
 

Thank you.
Will try this. However, if I go with this, how would I set the pattern
converter in the Web.config file to use the operationcontext{Status}.
Anyways, appreciate it.


Ron Grabowski wrote:
> 
> GlobalContext doesn't seem like the right place if you want to keep
> instance level values.
> 
> 
> If you've designed a WCF app why not just store things in OperationContext
> then make a PatternConverter to pull from there?
> 
>   "%d %level %oc{Status} %m%n"
> 
> 
> 
> 
> ________________________________
>  From: Joseph.r <ra...@gmail.com>
> To: log4net-user@logging.apache.org 
> Sent: Friday, June 1, 2012 2:24 PM
> Subject: Log4Net logs incorrect data
>  
> 
> I have a WCF service where in I use Log4Net for logging information to Sql
> Server database. I use Log4Net's GlobalContext to log some extra
> information, like Transaction Name, Status, Message, and few other stuff.
> Some of the important transactions within this system are Read, Write and
> Login.
> 
> The log should look like:
> 
> "Read" -------- "Success" -------- "Read xxx customer data"
> "Write" -------- "Success" -------- "Written xxx customer's data"
> "Login" -------- "Failure" -------- "User session already exists."
> Everything works fine when I run my normal tests - the logs are written to
> the database perfectly. However, recently I did a load test by using
> JMeter.
> The above mentioned three transactions were tested in 100 concurrent
> threads
> for 3 minutes. When I checked the DB logs, I found that some of the
> information were logged incorrectly.
> 
> Ex:
> 
> "Read" -------- "Success" -------- "User session already exists."
> "Write" -------- "Success" -------- "Read xxx customer data"
> Is this an issue with Log4Net GlobalContext not being thread safe? I tried
> using ThreadContext instead of GlobalContext, but looks like lots of
> information were not logged.
> -- 
> View this message in context:
> http://old.nabble.com/Log4Net-logs-incorrect-data-tp33946524p33946524.html
> Sent from the Log4net - Users mailing list archive at Nabble.com.
> 

-- 
View this message in context: http://old.nabble.com/Log4Net-logs-incorrect-data-tp33946524p33951719.html
Sent from the Log4net - Users mailing list archive at Nabble.com.

Re: Log4Net logs incorrect data

Posted by "Joseph.r" <ra...@gmail.com>.
Thank you.
Will try this. However, if I go with this, how would I set the pattern
converter in the Web.config file to use the operationcontext{Status}.
Anyways, appreciate it.


Ron Grabowski wrote:
> 
> GlobalContext doesn't seem like the right place if you want to keep
> instance level values.
> 
> 
> If you've designed a WCF app why not just store things in OperationContext
> then make a PatternConverter to pull from there?
> 
>   "%d %level %oc{Status} %m%n"
> 
> 
> 
> 
> ________________________________
>  From: Joseph.r <ra...@gmail.com>
> To: log4net-user@logging.apache.org 
> Sent: Friday, June 1, 2012 2:24 PM
> Subject: Log4Net logs incorrect data
>  
> 
> I have a WCF service where in I use Log4Net for logging information to Sql
> Server database. I use Log4Net's GlobalContext to log some extra
> information, like Transaction Name, Status, Message, and few other stuff.
> Some of the important transactions within this system are Read, Write and
> Login.
> 
> The log should look like:
> 
> "Read" -------- "Success" -------- "Read xxx customer data"
> "Write" -------- "Success" -------- "Written xxx customer's data"
> "Login" -------- "Failure" -------- "User session already exists."
> Everything works fine when I run my normal tests - the logs are written to
> the database perfectly. However, recently I did a load test by using
> JMeter.
> The above mentioned three transactions were tested in 100 concurrent
> threads
> for 3 minutes. When I checked the DB logs, I found that some of the
> information were logged incorrectly.
> 
> Ex:
> 
> "Read" -------- "Success" -------- "User session already exists."
> "Write" -------- "Success" -------- "Read xxx customer data"
> Is this an issue with Log4Net GlobalContext not being thread safe? I tried
> using ThreadContext instead of GlobalContext, but looks like lots of
> information were not logged.
> -- 
> View this message in context:
> http://old.nabble.com/Log4Net-logs-incorrect-data-tp33946524p33946524.html
> Sent from the Log4net - Users mailing list archive at Nabble.com.
> 

-- 
View this message in context: http://old.nabble.com/Log4Net-logs-incorrect-data-tp33946524p33951719.html
Sent from the Log4net - Users mailing list archive at Nabble.com.


Re: Log4Net logs incorrect data

Posted by Ron Grabowski <ro...@yahoo.com>.
GlobalContext doesn't seem like the right place if you want to keep instance level values.


If you've designed a WCF app why not just store things in OperationContext then make a PatternConverter to pull from there?

  "%d %level %oc{Status} %m%n"




________________________________
 From: Joseph.r <ra...@gmail.com>
To: log4net-user@logging.apache.org 
Sent: Friday, June 1, 2012 2:24 PM
Subject: Log4Net logs incorrect data
 

I have a WCF service where in I use Log4Net for logging information to Sql
Server database. I use Log4Net's GlobalContext to log some extra
information, like Transaction Name, Status, Message, and few other stuff.
Some of the important transactions within this system are Read, Write and
Login.

The log should look like:

"Read" -------- "Success" -------- "Read xxx customer data"
"Write" -------- "Success" -------- "Written xxx customer's data"
"Login" -------- "Failure" -------- "User session already exists."
Everything works fine when I run my normal tests - the logs are written to
the database perfectly. However, recently I did a load test by using JMeter.
The above mentioned three transactions were tested in 100 concurrent threads
for 3 minutes. When I checked the DB logs, I found that some of the
information were logged incorrectly.

Ex:

"Read" -------- "Success" -------- "User session already exists."
"Write" -------- "Success" -------- "Read xxx customer data"
Is this an issue with Log4Net GlobalContext not being thread safe? I tried
using ThreadContext instead of GlobalContext, but looks like lots of
information were not logged.
-- 
View this message in context: http://old.nabble.com/Log4Net-logs-incorrect-data-tp33946524p33946524.html
Sent from the Log4net - Users mailing list archive at Nabble.com.