Store additional <statement> debug information in the MDC
---------------------------------------------------------
Key: IBATISNET-80
URL: http://issues.apache.org/jira/browse/IBATISNET-80
Project: iBatis for .NET
Type: Sub-task
Reporter: Ron Grabowski
Assigned to: Gilles Bayon
Priority: Trivial
I was trying to debug some strange entires in my log files today (I added the
... part):
PreparedStatement : [SELECT ...]
Parameters: [EMAIL PROTECTED],1]]
Types: [EMAIL PROTECTED], System.Int32]]
PreparedStatement : [SELECT ...]
Parameters: [EMAIL PROTECTED],1]]
Types: [EMAIL PROTECTED], System.Int32]]
PreparedStatement : [SELECT ...]
Parameters: [EMAIL PROTECTED],1]]
Types: [EMAIL PROTECTED], System.Int32]]
PreparedStatement : [SELECT ...]
Parameters: [EMAIL PROTECTED],1]]
I realized that I had 100 <statement>s spread across 15 sql map files. It had
been a while since I last looked at this project so I had no clue were those
statements were being called from and why there were so many of them. It took
me a while to finally track down what was going on. It would have been very
helpful to see something like this in the log files:
Statement: [User.GetOne] PreparedStatement : [SELECT ...]
Statement: [User.GetOne] Parameters: [EMAIL PROTECTED],1]]
Statement: [User.GetOne] Types: [EMAIL PROTECTED], System.Int32]]
Statement: [User.GetOne] PreparedStatement : [SELECT ...]
Statement: [User.GetOne] Parameters: [EMAIL PROTECTED],1]]
Statement: [User.GetOne] Types: [EMAIL PROTECTED], System.Int32]]
Statement: [User.GetOne] PreparedStatement : [SELECT ...]
Statement: [User.GetOne] Parameters: [EMAIL PROTECTED],1]]
Statement: [User.GetOne] Types: [EMAIL PROTECTED], System.Int32]]
Statement: [User.GetOne] PreparedStatement : [SELECT ...]
Statement: [User.GetOne] Parameters: [EMAIL PROTECTED],1]]
I'm sure not everyone wants that much information; some of us want more even
more! A flexible solution may be to add this information to the log4net's MDC
scope. The line that creates the initial sql log:
if (_logger.IsDebugEnabled)
{
_logger.Debug("PreparedStatement : [" + command.CommandText + "]");
}
could be changed to this:
if (_logger.IsDebugEnabled)
{
log4net.MDC.Set(LOG4NET_MDC_PREFIX + "StatementCacheModelName",
statement.CacheModelName);
log4net.MDC.Set(LOG4NET_MDC_PREFIX + "StatementId", statement.Id);
log4net.MDC.Set(LOG4NET_MDC_PREFIX + "StatementResultMapId",
statement.ResultMap.Id);
_logger.Debug("PreparedStatement : [" + command.CommandText + "]");
}
In my case, I would have used this pattern in my Appender:
"%p %d (%c:%L) - Statement: %X{ibatisnet:StatementId} %m%n"
Maybe this additional information could be used as a way to dispaly execution
time statistics:
http://issues.apache.org/jira/browse/IBATIS-151
"%p %d (%c:%L) - Statement: %X{ibatisnet:StatementId}
%X{ibatisnet:ExecutionTime} %m%n"
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see:
http://www.atlassian.com/software/jira
