Jim is a senior consultant in Global Medical Applications at Wyeth Pharmaceuticals. He can be reached at mangionej @yahoo.com.
While we routinely standardize project details such as naming conventions and abstraction layers of corporate architectures, standardized logging often gets overlooked. Consequently, each application ends up logging messages differently. Can we do better? Absolutely. For the enterprise to accurately gauge the health of its IT assets across applications and gather pertinent metrics to support those findings, we need true enterprise-level logging. In this article, I propose a common way to meet this objective, using Microsoft's SQL Server 2005 as an example. In the process, I present a "Hello Broker" WinForm client using the Log4NET framework. The complete source code for the client-testing application (available electronically, see "Resource Center," page 4) posts test messages to each of the log severities so you can trace them through the queues.
The requirements for a logging system include:
- A common schema for log messages.
- A common set of severities.
- A centralized, loosely coupled logging service with a single point of entry and published API.
- A scalable architecture.
- The ability to dynamically set up and change application severities/destinations centrally (without touching each individual application configuration).
These specifications—especially the scalability and asynchronous features—point to a traditional middleware, queuing-type implementation.
Logging Service Architecture
Figure 1 is a high-level view of the proposed logging service. Again, I am implementing a queuing-based system, which aids in scalability and performance of client applications using this service. At the core is the Central Log Queue, which accepts all log message types from all registered applications. Messages are published to this queue from the public API Log Publisher. This is the only way a message can enter the queue. Other publishers may exist to translate proprietary log messages to the standard message format our service accepts, but they must then call the Log Publisher to post the messages. (This is demonstrated in the Log4NET client implementation.)
The Central Log Queue has a single subscriber type, a message router that consumes each message and interrogates its contents to determine what destination queue(s) to route to. Messages are routed based on their severity and the application's configuration details. Each application that wants to use this service must register by adding information into the log service metadatabase. For routing purposes, a mapping of each severity to one or more destinations is all that is necessary. Logs that are published with severities that aren't mapped simply vaporize—they are consumed and ignored so the queue doesn't jam up.
Each destination is also a queue. This again facilitates a scalable architecture where the service can distribute the workload of more popular destinations across multiple queues. Each destination queue has its own subscriber type that, upon consuming a message, performs the particular function that places that message at the end point—the real destination. Here, the severity can be ignored for purposes of workflow because these subscribers are only interested in dumping all messages to its relevant destination. I have defined three destinations:
- E-mail, where recipients are defined in the application configuration of the service.
- Log database, a central repository to capture important severities from all applications for reporting and analytics.
- Windows application events, to act as a gateway to other monitoring or auditing tools if applicable.
Figure 2 defines the metadatabase used for configuring individual applications to run in the log service. This is a straightforward design in which the schema consists of the core entities for configuring each application. The Application table stores information about each registered application, including e-mail information for that type of destination, and current logging levels. Severity defines the five supported levels, from INFO to FATAL. Destination defines each supported destination type and binds that to a Service Broker service. Putting it all together is the Central_Log_Configuration table that defines what each application's severity-to-destination mappings are.
The Service Broker
SQL Server 2005 includes a reliable messaging framework within its database engine called "Service Broker." It has most of the common queuing functionality you would expect from messaging middleware, including support for transactions, message ordering, and the ability to scale and provide service programs, which consume messages and run multiple instances of themselves based on the load on the queue. Comparisons can be made between this and the Java Messaging Service, with those service programs acting like Message-Driven Beans (MDBs).
When opening the SQL Server Management Studio, you notice some sections in each user database; namely, a section called "Service Broker" that has some of these object types:
- Message Type. Defines the name and type of a particular message that is used by a service.
- Contract. Defines which message types to use and what the associated end points are between two services.
- Service. Defines a set of related tasks based on a particular queue and contract, and links a conversation to a queue.
- Queue. The persistent storage for messages. An internal table type.
Another important part of the broker is how it communicates. "Conversations" are the means by which messages are sent to a queue (by way of a service) and how responses are sent back to the originator (in the case of dialogues). For this logging system, you don't need to worry about true dialogues, only about sending/receiving messages. Although this still must be done through conversations, the implementation is simplified.
Publishing to the Central Log Queue
Assuming the database is already created, the first main Service Broker component to build is the Queue. Before executing a one-line SQL statement that does this, however, you need to define what the XML log message that gets queued looks like; see Example 1. Application_Name and Severity_Cd must exist in their respective tables, and the application must have a destination configured for this particular severity. Now you can setup the appropriate plumbing to move this log message into a queue (including the queue object itself); see Example 2.
The WELL_FORMED_XML message type validation ensures that nonXML code doesn't get into the queue. There are also other choices, including one that defines a particular schema to validate against. Creating a contract for the system is simplified because this is a one-way message only—no response is needed. Instead of SENT BY ANY, you specify a message type for sending by INITIATOR, and another message type for sending to TARGET. Finally, the creation of the service binds everything together.
How do you get a message published? This is done by the Log Publisher stored procedure in Listing One. Sending an XML message isn't that much work. First, a dialog started against the LogService defines which queue the message goes into and which contract is used for the conversation. You still need to define a from/to service, but because this isn't a true dialog, they can be the same. A unique message handle is received from this statement. That handle is then used to send the message.
Log messages sit in the queue until they are consumed by a service program, which attaches itself to the queue and receives the messages for processing. In this case, the processing is simply publishing to another queue.
Routing Messages To Destination Queues
Once messages are in the Central Log Queue, they are received by a program that—based on the application and severity—routes that message down to a destination queue. To do this, you'll notice new Service Broker syntax in SQL. A basic SQL statement to receive (remove) a message off a queue looks like this:
RECEIVE cast(message_body as
nvarchar(max)) FROM [CentralLogQueue]
If you want to block on receive until a message arrives, then you can wrap the aforementioned code in a WAITFOR statement and define a time interval to fall through:
WAITFOR
(
RECEIVE cast(message_body as
nvarchar(max)) FROM [CentralLogQueue]
), TIMEOUT 5000
Armed with these basic statements to retrieve messages, you can now build the most complex part of the system—the Router stored procedure in Listing Two. The core algorithm is:
- Get a message off the queue.
- Look up the application's configuration and determine what destinations to publish the message to based on the severity of the message.
- For each destination (service), create a dialog and send the message.
Once the message arrives, OpenXML() returns the application and severity. From this, you can query the configuration tables to return the destination and service names you need to publish to. On each destination, you dynamically bind the service name to the begin dialog, and using the same LogServiceContract used for the original Publisher procedure, you send the exact same LogRequest message you received to the destination queues defined by the service name. Note the use of LogServiceGUID. At the beginning of this procedure, you cache this value. If you were hosting the same service (same name) on multiple databases, you would need to choose which GUID to use.
Once you have the router that will keep listening for messages, it's invocation time. You can run the thing via command line to test it, but there's a better way to do this in production—let the queue manage it:
ALTER QUEUE [CentralLogQueue] WITH
ACTIVATION ( STATUS =
ON, PROCEDURE_NAME =
[SPRouter], MAX_QUEUE_READERS =
10 , EXECUTE AS N'dbo' )
The queue will automatically activate SPRouter once a message is published. As the load on the queue increases, more instances of the service program are invoked up to the max readers (in this case, 10). Once these programs are running, however, they cannot be shut off unless the queue is disabled. If the load on the queue decreases, altering the activation status to OFF keeps new instances of the program from running (if max isn't hit), but will not shut down live ones. This functionality exists to keep the broker from killing processes in midstream (because it probably wouldn't know if the program is waiting for a message or churning through one). If the broker's event model was easily exposed and delegation was used to invoke the service program, you would not need to continually return to the waitfor. This would let the engine adjust the instances downward without concern over where the process is.
Destination Service Programs
Using the main algorithm from the Router, you can cut out the middle part (sending to another queue), replacing it with the specific code to send e-mail, insert into the Central Log Database, and post to the window's event log. Listings Three, Four, and Five (all available electronically) accomplish these tasks, respectively, although you may have your own methods for e-mail and event logging.
Testing the Service Using Log4NET
Apache's Log4NET (http://logging.apache.org/log4net/) is an open-source logging framework based on the Log4j project. The main goal of the framework is to allow easy inclusion of logging into applications, with the ability to define many destinations for outputting the logs, and filtering them based on severity. Within five minutes, you can introduce minimally a console-based logging mechanism into your .NET application. With a little more effort, you can extend that to such destinations as rolling files, SMTP, remoting, Window's event logs, and databases, which is where the integration point with our Central Logging System occurs.
Log4NET uses appenders to define destination paths to send log messages to. One such appender is ADONetAppender, which allows the writing of logs to a database either through defined SQL or stored procedures. Say you want any severities of Warning, Error, or Fatal to be sent to our Enterprise Logging Service (and keep the verbose logging of INFO and DEBUG on the client side only). What is needed is to define in the application's configuration file an instance of the ADONetAppender that maps to the Log Publisher stored procedure. This creates that bridge into the Central Log Queue.
Because the Log Publisher expects an XML Log Message, you need a translation of the Log4NET's log class prior to calling the procedure. To ensure all the messages are translated the same from any number of Log4NET implementations, you do this in a Log4NETLogPublisher stored procedure; see Listing Six (available electronically). The ADONetAppender configuration that defines the necessary plumbing needed to pass the log fields into the stored procedure is defined below that. The @ApplicationName is passed in here, as well as the level being set to WARN. In the Central Logging configuration, you need to have at least one destination mapped to WARN, ERROR, and FATAL for this application.
Conclusion
For organizations looking to upgrade to SQL Server 2005 and do more in respect to enterprise-application logging and exception handling, this project could act as a conduit for exploring the feature set of Microsoft's new Service Broker to produce a trimmed-down but functional and scalable logging service.
DDJ
-- This procedure will receive an XML log record and submit to the Central
-- Queue via the Log Service.
CREATE PROCEDURE [dbo].[SPLogPublisher]
@msgXML [nvarchar](max)
WITH EXECUTE AS CALLER
AS
declare @msgHandle uniqueidentifier
begin transaction
begin dialog conversation @msgHandle
from service [LogService] to service 'LogService'
on contract [LogServiceContract];
send on conversation @msgHandle message type [LogRequest] (@msgXML)
end conversation @msgHandle
commit
Back to articleListing Two
CREATE PROCEDURE [dbo].[SPRouter]
WITH EXECUTE AS CALLER
AS
-- This is a Service Program that will receive Log Messages as xml from the
-- Central Queue
-- (LogService) and route them depending on the Log_Configuration metadata to
-- the appropriate
-- Destination Queues (App, DB and/or Email Services).
--
-- Workflow:
-- a) receive an xml log message from the CentralLogQueue
-- b) for each destination_id that is setup in the Log Configuration for the
-- Application_Name and Severity_Cd tags in the message log, post the
-- xml log message to that destination queue.
--
declare @conversation_handle uniqueidentifier
declare @message_body nvarchar(MAX)
declare @message_type_name sysname
declare @xml_doc_handle int; -- used by XPath to create a doc in memory
declare @xml_doc varchar(MAX); -- receives xml doc from the sp_preparedoc call
-- database ID for these services (assume they all exist in same database)
declare @LogServiceGUID uniqueidentifier;
-- store the results of this xml log into a temp table for querying to find
-- destinations
declare @xml_log_app_and_severity table ( application_name varchar(32),
severity_cd varchar(32) )
-- will store each destination and service that this log is going to goto
declare @destinations table ( destination_name varchar(32),
service_name varchar(32) )
-- used for working on individual rows from the destinations table above
declare @destination varchar(32)
declare @service varchar(32)
declare @msgHandle uniqueidentifier
-- cache this for use when publishing the messages to destination queues
SELECT @LogServiceGUID = service_broker_guid
FROM sys.databases
WHERE database_id = DB_ID('LogService');
-- Keep this alive. Else the broker will call this procedure for every message.
while ( 1=1 )
begin
-- receive the next message off the queue
waitfor
(
receive top(1)
@message_body=message_body,
@message_type_name=message_type_name,
@conversation_handle=conversation_handle
from [CentralLogQueue]
)
-- insure the message is of the proper type (should ALWAYS be)
if @message_type_name = 'LogRequest'
begin
-- setup an internal representation of this XML doc
exec sp_xml_preparedocument @xml_doc_handle output, @message_body
-- get the destination names based on application and severity of this log
-- and load into temp destination table
insert into @xml_log_app_and_severity
select application_name, severity_cd
from OpenXML(@xml_doc_handle, '/ROOT/CentralLogMessage',2)
with (Application_Name varchar(64),
Severity_Cd varchar(32))
-- lookup the destination(s) via the configuration
insert into @destinations
select d.destination_name, d.service_name
from destination d, central_log_configuration clc,
application a,
severity s,
@xml_log_app_and_severity x
where x.application_name = a.application_name and
x.severity_cd = s.severity_cd and
clc.application_id = a.application_id and
clc.severity_id = s.severity_id and
clc.destination_id = d.destination_id and
a.logging_level >= s.severity_id
-- publish the log to each destination by iterating through the table
declare cDestinations cursor fast_forward for select * from @destinations
open cDestinations
fetch next from cDestinations into @destination, @service
while @@fetch_status = 0
begin
-- publish message to designated service
-- @destination name is only needed for debugging purposes
begin transaction
begin dialog conversation @msgHandle
from service @service
to service @service, @LogServiceGUID
on contract [LogServiceContract];
send on conversation @msgHandle message type [LogRequest]
(@message_body)
end conversation @msgHandle
commit transaction
-- get the next row (service) to publish this message too
fetch next from cDestinations into @destination, @service
end
close cDestinations
deallocate cDestinations
-- clean up temp tables
delete from @xml_log_app_and_severity
delete from @destinations
-- clean up
exec sp_xml_removedocument @xml_doc_handle
end
else
begin
-- wrong type of message, or an error occurred.
print N'Central Logging: Invalid message type received for DIALOG HANDLE: ' +
cast( @conversation_handle as varchar(256) ) + N' XML MESSAGE: ' +
cast( cast( @message_body as XML ) as varchar(MAX));
end
end -- loop
Back to article
