Sitecore Logging to the database (part 2 – earning the good developer badge)

This is a follow-up to my introduction on customizing Sitecore logging to use a database instead of a flat file.  This post covers some advancements over the basics in the first post, and sets the table for a conversation about performance and Sitecore database logging in the follow-up.

Centralizing the Connection String

If the database to write log output to is referenced in other capacities in the implementation, a database connection string pointing to the database will likely reside in app_config/ConnectionStrings.config. To avoid having multiple connection string configurations to the same database (one in the <log4net> definition and one in the <connectionStrings> definition), you may want to centralize the log4net connection string information and make exclusive use the ConnectionStrings.config entry. This eases maintenance and earns you the “good developer” badge for this functionality.

The following node should be added to the <appender> XML configuration, using our CustomDBAppender from the earlier post as the example:

<connectionStringName value="logRepository"/>

This can replace the entry for <param name=”connectionString” …

And in the App_Config/ConnectionStrings.config file one needs to add something such as the following:

<add name="logRepository" connectionString=" user id=[login];password=[pwd];Data Source=[server];Database=[CustomLogDB]" />

The DBAppender class in our example needs modifications to support this centralization of the connection string. Specifically, add a simple string property to the class to support the custom <connectionStringName/> node we added previously:

private string _cnString = String.Empty;
public string connectionStringName
    return _cnString;
    _cnString = value;

And to bring in the new connection string source to the DBAppender class, one should add an override of the ActivateOptions method as follows:

public override void ActivateOptions()
  this.ConnectionString = System.Configuration.ConfigurationManager.ConnectionStrings[connectionStringName].ConnectionString;

Using a Stored Procedure

The general performance benefits of using a Stored Procedure over plain SQL Command Text are well-known. When logging to the database, the potential for easier execution plan re-use in SQL Server is one reason to use a stored procedure; another good reason is the ability to limit the amount of “logic” within web.config – using a stored procedure can make maintenance easier. Again, let’s earn that “good developer practice” badge!

The steps to alter the configuration to use a stored procedure are straight forward:
1. Create a stored procedure in the database that will encapsulate the SQL INSERT statement:

	@log_date		DateTime
	, @thread		varchar(255)
	, @log_level	varchar(255)
	, @logger		varchar(255)
	, @machine		varchar(4000)
	, @message		varchar(4000)
	, @custom		varchar(4000)
	INSERT INTO CustomLog ([Date],[Thread],[Level],[Logger],[Message],[Machine],[Custom]) 
	VALUES (@log_date, @thread, @log_level, @logger, @message, @machine, @custom)

2. Change the XML configuration for the node in web.config to reference the stored procedure:

<appender name="DatabaseAppender" type="CustomDBAppender.DBAppenderWrapper, CustomDBAppender" >
<param name="CommandText" value="logFromSitecore" />
<param name="CommandType" value="StoredProcedure" />

This is all that’s required for the logging to now run through a stored procedure instead of using plain SQL command text. In the follow-up post about performance, I will return to this topic in more detail . . . but this covers the mechanics of using a stored procedure with your database logging.

Data Volume

No matter which approach one takes to managing the connection string or the question of stored procedures vs in-line SQL, managing the volume of data logged to the database is an important consideration.
Care should be taken in configuring the amount of data logged, just to guard against an overwhelming volume of database writes becoming a bottleneck. Log4net supports this in a number of ways, one method is the “priority” setting that is under the node in the log4net web.config definition. The “priority” setting filters out log messages below that value, so a < priority value=”WARN”/> would only write WARN messages and higher. You may want to consider using the ERROR value, even, to be more conservative about this. For production environments, I recommend updating the priority to WARN or ERROR for the configuration defined in section above. By default, Sitecore sets this to INFO. Change it to something like the following:

  <priority value="WARN"/>

BufferSize Setting

The ADONetAppender keeps a buffer of log messages in memory, and persists the messages to the database once the buffer is full. This buffer can be configured via the “bufferSize” setting () under the node in the log4net web.config definition. By default, Reflector tells me the value is 512. When checking the database table for a specific message, it’s important to know that a specific recent message might be buffered and not written to the database because of this setting. In a production environment, Sitecore recommends against setting a bufferSize value lower than the default (512), for performance reasons; a value of “1,” for example, would write every log message to the database as soon as it is generated and could create considerable traffic to the database. Depending on the environment, one may consider setting this bufferSize value higher than the default; in a development environment, however, a value of “1” may be desireable to have messages written immediately to the database.

Recognizing that the database appender is buffering messages, it’s conceivable that a server outage could result in a loss of any buffered messages that haven’t been written to the database. In such a circumstance, the logged activity could be vital to diagnosing the circumstances of the outage. With this scenario in mind, I recommend the following:

Maintain a minimal file-based Sitecore log on the server (keeping only the most recent 2 days, for example); this would have a better chance of capturing any log messages potentially lost due to a sudden outage.  In a hypothetical outage situation, one could resort to checking the file-based log on the server in question.  

ReconnectOnError Setting

The ADONetAppender has a “ReconnectOnError” setting which controls if this appender will try to reconnect to the database on error. The default behaviour is for the appender to not try to reconnect to the database if an error occurs (ReconnectOnError is false by default). Given a scenario where there’s a temporary database connection problem, subsequent logging events are discarded if the ReconnectOnError setting is set to false. To force the appender to attempt to reconnect to the database, set this property to true in the definition in web.config:

  <ReconnectOnError value="true"/>

Note: When the appender attempts to connect to the database there may be a delay of up to the connection timeout specified in the connection string. This delay will block the calling application’s thread. Until the connection can be reestablished this potential delay may occur multiple times. To mitigate such a scenario, one might consider introducing true asynchronicity into the ADONetAppender (more on this later).

OK, to recap these two posts on logging to the database with Sitecore:

  • Post one (enough to be dangerous):
    • The custom ADONetAppender Class
    • Log Database and Table
    • XML Configuration
  • Post two (earning the good developer badge):
    • Centralizing your ConnectionString
    • Using a Stored Procedure
    • Advanced settings to consider

In the third installment, I’ll address performance in some detail and asynchronicity.


2 thoughts on “Sitecore Logging to the database (part 2 – earning the good developer badge)

Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s