You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4net-dev@logging.apache.org by Cliff Burger <cl...@gmail.com> on 2006/06/21 19:57:42 UTC

Questions about ADONetAppender (Resent with correct subject)

Sorry ... I just realized I sent under the thread "log4net 1.2.10 Released"
which would cause some confusion.

2006/6/21, Cliff Burger <cl...@gmail.com>:
>
> Questions about ADONetAppender
>
> I'm considering creating a MSSQLAppender for my company's use, as we are
> primarily an MS Shop. General questions:
>
> Is anyone else already working on this?
> Are the issues I'm addressing valid?
> Should some of the changes I want to make be promoted into the general
> purpose ADONetAppender?
>
> Save cost of reflected object creation.
> The ADONEt appender appears to create a
> System.Data.SqlClient.SqlConnection object via reflection each time it
> sends the buffer. In my experience, reflection is a little slow. Given that
> we use this in non-lossy mode, it must create a connection using reflection
> every time a message is sent. Avoiding this cost requires a  MSSQLAppender
> in the current implementation. Are my assumptions about the performance of
> the Activator correct or incorrect?
>
> Another option that would work in a ADONETAppender case is to create the
> connection object and leave the instance around, using Open / Close rather
> than dispose. Object would be disposed would only in "OnClose". Rathering
> than incurring costs of creating an object via reflection for each message,
> we only incur the cost once, during the creation of the Appender. Does this
> run the risk that configurations are changed during a running program, and
> not picked up by the appender, or is the appender instance recreated in this
> case?
>
> Connection behavior:
> ADONetAppender currently creates a new connection object and opens it each
> time a buffer is sent. It holds onto the instance and open connection until
> 1) the logger is "Closed" or 2) A message is sent. It has a somewhat silly
> behavior of closing and reopening the connection right before sending the
> message - but not closing it after the message is sent. We don't get the
> benefit of avoiding cost of re-opening a connection, but also don't get the
> benefit of keeping connections closed when not in use.
>
> Option a: The most performant behavior for unpooled connections would be:
> Keep the connection object open until the logger is closed. Before a message
> is sent, check that the connection is open ... but don't reopen if a
> connection object is present and open. This (like the current behavior) is
> slightly un-safe if transactions are used ... I've previously had problems
> with this appender leaving uncommitted transactions and locking tables.
>
> Option B: The most sensible behavior for pooled connections (and safest)
> would be: Open connection, send buffered messages, and close the connection.
> This gives fine performance with pooled connections where connection isn't
> really reopened/ closed, it's just returned to the pool. This would incur a
> performance costs in non-pooled connections, but is no different from
> current behavior. Closing the connection ensures that any hanging
> transactions are committed or rolled back.
>
> The safe behavior is to use option B - this is also the behavior which
> will make our DBA happiest. The best solution might be to control the
> behavior of connections via configuration to optimize for pooled / nonpooled
> scenarios - but I probably won't take the time for this in my extension of
> this appender.
>
> Transaction behavior:
> When transactions are used with this appender, it sometimes results in
> locking the log table - the transactions were left hanging uncommitted. The
> default behavior is to use transactions. I haven't had time to determine
> exactly what causes the problem. Given that the risk exists, and when it
> occurs the consequences are severe (can't do anything at all with the log
> table), I'd like to set the default behavior to NOT use transactions.
>

Re: Questions about ADONetAppender (Resent with correct subject)

Posted by Cliff Burger <cl...@gmail.com>.
I'll try the cloning functionality. First I need to test my assumptions
about performance of creating via reflection ... I could be totally off. I
usually use it in plug-in loads, etc that just load stuff once. First use of
reflection is known to be slow in .NET 1-1 (building type caches, etc).
Second use might not be so bad, particularly since this code uses the
System.Type rather than strings type names.  I've got a few timing harnesses
that I'll run it through.

Open / closing connection
I discovered two hours after I sent previous post that I was horribly wrong
on open / close behavior. I misread an "if" statement. As I now understand
it, the connection is only recreated / reconfigured when the connection
fails - it's reopened only if reconnectonerror=true. It's only closed when
reopening it, or when the appender is closed.

My only reasons left to open and close connections around sending the buffer
are: 1) avoid leaving transactions open in error cases 2) as a general
practice, its a little safer to not leave db connections open.

I'm testing 1.2.10 behavior now to see how important item 2 is. In my web
service, v 1.2.9 would end up with a monstrous number of open connections
for the logger (it could reach 40-80 connections within an hour of
startup)... but there's a known bug on this patched in 1.2.10.

I would have no reason left at all to open / close the connections with each
SendBuffer method if I can figure out a way to ensure that transactions are
closed in a timely manner and thus generally avoid locking the target table.
Closing the connection is just the surest way to kill the transaction
immediately, if the code loses the connection or transaction object somehow.
To be honest, I screw up transactions frequently when I use them from .NET
code -- which is an indication that I don't know enough about this topic.
Any suggestions on what to start looking at in this?

That config snippet is vastly more concise than mine ...I don't see the
element "connectionStringAppSettingsKey" in the SDK. Is this an extension
that goes and pulls the config setting from appsettings? Gives me
interesting ideas -- if I'm overriding the class anyway ... using a hard
coded SQL command with params could save my devs a vast amount of
configuration file space. We all log using exactly the same procedure, same
database ... and then use "logging_application, hostname, user" parameters
to distinguish various applications in the log.

2006/6/21, Ron Grabowski <ro...@yahoo.com>:
>
> Minor changes like this may help:
>
> if (connectionTypeIsCloneable)
> {
>   return (IDbConnection) ((ICloneable)connectionType).Clone();
> }
> else
> {
>   return (IDbConnection) Activator.CreateInstance(connectionType);
> }
>
> but its difficult to know without profiling the code. Can you assemble
> a few configurations (and/or test cases) that you think might be slow?
> I'm curious about this comment:
>
> "
> It has a somewhat silly behavior of closing and reopening the
> connection right before sending the message - but not closing it after
> the message is sent.
> "
>
> That case might occur if there was a previous error with
> ReconnectOnError is set to true. The connection will be reset, the
> message logged, and the connection left open in anticipation for
> futuree messages.
>
> The AdoNetAppender can be a little too verbose sometimes. I use this
> snippet of code in my config file:
>
> <appender name="CompanyAdoNetAppender"
>   type="Company.Log4Net.AdoNetAppender">
>   <connectionStringAppSettingsKey value="developmentDB" />
> </appender>
>
> --- Cliff Burger <cl...@gmail.com> wrote:
>
> > Sorry ... I just realized I sent under the thread "log4net 1.2.10
> > Released"
> > which would cause some confusion.
> >
> > 2006/6/21, Cliff Burger <cl...@gmail.com>:
> > >
> > > Questions about ADONetAppender
> > >
> > > I'm considering creating a MSSQLAppender for my company's use, as
> > we are
> > > primarily an MS Shop. General questions:
> > >
> > > Is anyone else already working on this?
> > > Are the issues I'm addressing valid?
> > > Should some of the changes I want to make be promoted into the
> > general
> > > purpose ADONetAppender?
> > >
> > > Save cost of reflected object creation.
> > > The ADONEt appender appears to create a
> > > System.Data.SqlClient.SqlConnection object via reflection each time
> > it
> > > sends the buffer. In my experience, reflection is a little slow.
> > Given that
> > > we use this in non-lossy mode, it must create a connection using
> > reflection
> > > every time a message is sent. Avoiding this cost requires a
> > MSSQLAppender
> > > in the current implementation. Are my assumptions about the
> > performance of
> > > the Activator correct or incorrect?
> > >
> > > Another option that would work in a ADONETAppender case is to
> > create the
> > > connection object and leave the instance around, using Open / Close
> > rather
> > > than dispose. Object would be disposed would only in "OnClose".
> > Rathering
> > > than incurring costs of creating an object via reflection for each
> > message,
> > > we only incur the cost once, during the creation of the Appender.
> > Does this
> > > run the risk that configurations are changed during a running
> > program, and
> > > not picked up by the appender, or is the appender instance
> > recreated in this
> > > case?
> > >
> > > Connection behavior:
> > > ADONetAppender currently creates a new connection object and opens
> > it each
> > > time a buffer is sent. It holds onto the instance and open
> > connection until
> > > 1) the logger is "Closed" or 2) A message is sent. It has a
> > somewhat silly
> > > behavior of closing and reopening the connection right before
> > sending the
> > > message - but not closing it after the message is sent. We don't
> > get the
> > > benefit of avoiding cost of re-opening a connection, but also don't
> > get the
> > > benefit of keeping connections closed when not in use.
> > >
> > > Option a: The most performant behavior for unpooled connections
> > would be:
> > > Keep the connection object open until the logger is closed. Before
> > a message
> > > is sent, check that the connection is open ... but don't reopen if
> > a
> > > connection object is present and open. This (like the current
> > behavior) is
> > > slightly un-safe if transactions are used ... I've previously had
> > problems
> > > with this appender leaving uncommitted transactions and locking
> > tables.
> > >
> > > Option B: The most sensible behavior for pooled connections (and
> > safest)
> > > would be: Open connection, send buffered messages, and close the
> > connection.
> > > This gives fine performance with pooled connections where
> > connection isn't
> > > really reopened/ closed, it's just returned to the pool. This would
> > incur a
> > > performance costs in non-pooled connections, but is no different
> > from
> > > current behavior. Closing the connection ensures that any hanging
> > > transactions are committed or rolled back.
> > >
> > > The safe behavior is to use option B - this is also the behavior
> > which
> > > will make our DBA happiest. The best solution might be to control
> > the
> > > behavior of connections via configuration to optimize for pooled /
> > nonpooled
> > > scenarios - but I probably won't take the time for this in my
> > extension of
> > > this appender.
> > >
> > > Transaction behavior:
> > > When transactions are used with this appender, it sometimes results
> > in
> > > locking the log table - the transactions were left hanging
> > uncommitted. The
> > > default behavior is to use transactions. I haven't had time to
> > determine
> > > exactly what causes the problem. Given that the risk exists, and
> > when it
> > > occurs the consequences are severe (can't do anything at all with
> > the log
> > > table), I'd like to set the default behavior to NOT use
> > transactions.
> > >
> >
>
>

Re: Questions about ADONetAppender (Resent with correct subject)

Posted by Ron Grabowski <ro...@yahoo.com>.
Minor changes like this may help:

 if (connectionTypeIsCloneable)
 {
  return (IDbConnection) ((ICloneable)connectionType).Clone();
 }
 else
 {
  return (IDbConnection) Activator.CreateInstance(connectionType);
 }

but its difficult to know without profiling the code. Can you assemble
a few configurations (and/or test cases) that you think might be slow?
I'm curious about this comment:

"
It has a somewhat silly behavior of closing and reopening the
connection right before sending the message - but not closing it after
the message is sent.
"

That case might occur if there was a previous error with
ReconnectOnError is set to true. The connection will be reset, the
message logged, and the connection left open in anticipation for
futuree messages.

The AdoNetAppender can be a little too verbose sometimes. I use this
snippet of code in my config file:

 <appender name="CompanyAdoNetAppender" 
  type="Company.Log4Net.AdoNetAppender">
  <connectionStringAppSettingsKey value="developmentDB" /> 
 </appender>

--- Cliff Burger <cl...@gmail.com> wrote:

> Sorry ... I just realized I sent under the thread "log4net 1.2.10
> Released"
> which would cause some confusion.
> 
> 2006/6/21, Cliff Burger <cl...@gmail.com>:
> >
> > Questions about ADONetAppender
> >
> > I'm considering creating a MSSQLAppender for my company's use, as
> we are
> > primarily an MS Shop. General questions:
> >
> > Is anyone else already working on this?
> > Are the issues I'm addressing valid?
> > Should some of the changes I want to make be promoted into the
> general
> > purpose ADONetAppender?
> >
> > Save cost of reflected object creation.
> > The ADONEt appender appears to create a
> > System.Data.SqlClient.SqlConnection object via reflection each time
> it
> > sends the buffer. In my experience, reflection is a little slow.
> Given that
> > we use this in non-lossy mode, it must create a connection using
> reflection
> > every time a message is sent. Avoiding this cost requires a 
> MSSQLAppender
> > in the current implementation. Are my assumptions about the
> performance of
> > the Activator correct or incorrect?
> >
> > Another option that would work in a ADONETAppender case is to
> create the
> > connection object and leave the instance around, using Open / Close
> rather
> > than dispose. Object would be disposed would only in "OnClose".
> Rathering
> > than incurring costs of creating an object via reflection for each
> message,
> > we only incur the cost once, during the creation of the Appender.
> Does this
> > run the risk that configurations are changed during a running
> program, and
> > not picked up by the appender, or is the appender instance
> recreated in this
> > case?
> >
> > Connection behavior:
> > ADONetAppender currently creates a new connection object and opens
> it each
> > time a buffer is sent. It holds onto the instance and open
> connection until
> > 1) the logger is "Closed" or 2) A message is sent. It has a
> somewhat silly
> > behavior of closing and reopening the connection right before
> sending the
> > message - but not closing it after the message is sent. We don't
> get the
> > benefit of avoiding cost of re-opening a connection, but also don't
> get the
> > benefit of keeping connections closed when not in use.
> >
> > Option a: The most performant behavior for unpooled connections
> would be:
> > Keep the connection object open until the logger is closed. Before
> a message
> > is sent, check that the connection is open ... but don't reopen if
> a
> > connection object is present and open. This (like the current
> behavior) is
> > slightly un-safe if transactions are used ... I've previously had
> problems
> > with this appender leaving uncommitted transactions and locking
> tables.
> >
> > Option B: The most sensible behavior for pooled connections (and
> safest)
> > would be: Open connection, send buffered messages, and close the
> connection.
> > This gives fine performance with pooled connections where
> connection isn't
> > really reopened/ closed, it's just returned to the pool. This would
> incur a
> > performance costs in non-pooled connections, but is no different
> from
> > current behavior. Closing the connection ensures that any hanging
> > transactions are committed or rolled back.
> >
> > The safe behavior is to use option B - this is also the behavior
> which
> > will make our DBA happiest. The best solution might be to control
> the
> > behavior of connections via configuration to optimize for pooled /
> nonpooled
> > scenarios - but I probably won't take the time for this in my
> extension of
> > this appender.
> >
> > Transaction behavior:
> > When transactions are used with this appender, it sometimes results
> in
> > locking the log table - the transactions were left hanging
> uncommitted. The
> > default behavior is to use transactions. I haven't had time to
> determine
> > exactly what causes the problem. Given that the risk exists, and
> when it
> > occurs the consequences are severe (can't do anything at all with
> the log
> > table), I'd like to set the default behavior to NOT use
> transactions.
> >
>