Log4Net Users Mailing List

Joseph.r | 1 Jun 2012 20:24

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.

(Continue reading)

headers

Ron Grabowski | 3 Jun 2012 01:22

Re: Log4Net logs incorrect data

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 <rajesh.joseph <at> gmail.com>
To: log4net-user <at> 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.

headers

Joseph.r | 3 Jun 2012 03:20

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 <rajesh.joseph <at> gmail.com>
> To: log4net-user <at> 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.

headers

Ron Grabowski | 4 Jun 2012 23:19

Re: Log4Net logs incorrect data

Add a custom converter to your PatternLayout:

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

From: Joseph.r <rajesh.joseph <at> gmail.com>
To: log4net-user <at> 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 <rajesh.joseph <at> gmail.com>
> To: log4net-user <at> 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.