Sometimes, bugs only show up when the Web Service is serving a large number of requests. Setting breakpoints may not help if the behavior does not show up when things are slowed down (and nothing slows a service more than a breakpoint). To handle this, you enter the unhappy world of reviewing trace data. Because breakdown under load happens quite frequently, I recommend that you audit every entry point into the Web Service itself. By storing that information, the person analyzing the failure can recreate an accurate picture of what was happening at the time of the failure. This section will cover the things you should store at all times so that you can analyze where your code failed. As a developer, you will want to use this in conjunction with trace levels and such. The trace classes are typically covered quite well in introductory texts. If you do not have a basic reference, I would recommend that you purchase one very soon.
When auditing this information, do not place it in a file. As the file grows, and it will grow quickly under load, you will see file writes take longer and longer. Instead, consider logging your audit data to a database. Simple database inserts typically take very little time. As an added bonus, the database operations probably will not slow down as the amount of information grows. You may wind up making a large number of calls to figure out exactly what is going wrong. Decide what data you need to collect (each case will be different) and store it. A stored procedure may get you the best performance and impact the overall application the least.
For practical purposes, you might want to build this apparatus ahead of time, just to audit Web Service activity. When bugs start popping up, you can add extra lines of code to insert extra audit records. Some data items you may want to record are as follow:
Method identifier. This can be a numeric value or a string.
Date and time the audit record was created by the Web Service.
Bit of data indicating whether the audit record represents success, failure due to server problems, failure due to client problems, or none of the above.
User-defined string specific to the audit record. This can contain extra data useful in debugging or to give the audit record extra meaning.
Additionally, you will want to define a record key. A numeric index will work well. Because auditing should happen in the background, a form of delayed writes works very well. Either execute the recording of the audit record in a low priority asynchronous process or put the audit record in a queue to be stored in the database later. Writes to a message queue are often faster than a database insert.
Believe it or not, building an auditing mechanism is one of the best proactive things you can do. Discuss this with your database administrator (DBA) and figure out how often you want to archive the audit data. Your DBA may want to have the audit records exist in a separate database to make archiving easy. Regardless, you will see benefits from implementing auditing before problems happen.
Because auditing is so important, let's take a look at an example—a custom SOAP attribute that will log method calls in a synchronous manner. This attribute does not handle the asynchronous logging previously recommended. It does do the basic logging, though. To use the class, you need to have a SQL Server database installed. The SQL isn't too complex. This includes the Microsoft Data Engine (MSDE), a freely distributable database bundled with many applications. You can get MSDE at http://msdn.microsoft.com/vstudio/msde/msde.asp.
This code will work on any existing database that has a table named Audit and a stored procedure named AddAudit. The SQL to create the table and stored procedure is shown in Listing 5.2. The sql file, auditData.sql, contains some extra code that handles removing the table and procedure if they already exist.
-- Create the Audit table CREATE TABLE [dbo].[Audit] ( [ID] [int] IDENTITY (1, 1) NOT NULL , [startDate] [datetime] NOT NULL , [endDate] [datetime] NOT NULL , [result] [int] NOT NULL , [methodName] [nvarchar] (100) NOT NULL , [otherData] [nvarchar] (500) NULL ) ON [PRIMARY] GO ALTER TABLE [dbo].[Audit] WITH NOCHECK ADD CONSTRAINT [PK_Audit] PRIMARY KEY CLUSTERED ( [ID] ) ON [PRIMARY] GO -- Create the AddAudit stored procedure CREATE PROCEDURE AddAudit @startDate as DATETIME, @endDate as DATETIME, @result as INT, @methodName as NVARCHAR(100), @otherData as NVARCHAR(500) AS INSERT INTO Audit (startDate, endDate, result, methodName, otherData) VALUES ( @startDate, @endDate, @result, @methodName, @otherData) GO |
After the database has been set up, you will need a way to tell any code how to open a connection to the database. The web.config file for any Web Service using the custom attribute about to be shown must contain the database connection string in the appSettings section of the configuration file. The name of the value must be AuditDB. Listing 5.3 shows a sample version of this section. The connection string points to the Northwind database that is installed by default with SQL Server.
<appSettings> <add key="AuditDB" value= "user id=sa;password=dbpassword;initial catalog=northwind;data source=localhost;Connect_Timeout=30"/> </appSettings> |
How is this used? To answer that, we need to look at the first of three classes used to audit the Web Service. The AuditEntry class is used to store our audit data and then save it to a database when the complete round trip (request and response) is all but done. The class contains some simple properties as well as a Save method that writes the properties to the database. This class assumes that users have already executed the SQL in Listing 5.2 and added the value to the web.config file as shown in Listing 5.3. Listing 5.4 shows the complete listing for this class.
Imports System.Reflection Imports System Namespace com.scottseely Public Enum CallResult ServerFailure = 1 ClientFailure = 2 Success = 10 End Enum Public Class AuditEntry Private m_methodName As String Private m_startTime As DateTime Private m_endTime As DateTime Private m_callResult As callResult Private m_otherData As String = "" ' Stores the name of the method being audited Public Property methodName() As String Get Return m_methodName End Get Set(ByVal Value As String) m_methodName = Value End Set End Property ' Stores the time that the audit began Public Property startTime() As DateTime Get Return m_startTime End Get Set(ByVal Value As DateTime) m_startTime = Value End Set End Property ' Stores the time that the audit finished Public Property endTime() As DateTime Get Return m_endTime End Get Set(ByVal Value As DateTime) m_endTime = Value End Set End Property ' Stores the result of the SOAP method Public Property callResult() As callResult Get Return m_callResult End Get Set(ByVal Value As callResult) m_callResult = Value End Set End Property ' Stores any other data related to the method call Public Property otherData() As String Get Return m_otherData End Get Set(ByVal Value As String) m_otherData = Value End Set End Property ' Saves the audit information to a database Public Sub Save() Try ' Get the connection string from the ' application using this library Dim connStr As String = _ System.Configuration.ConfigurationSettings. _ AppSettings.Item("AuditDB") Dim conn As New SqlClient.SqlConnection(connStr) conn.Open() Dim comm As New SqlClient.SqlCommand() 'Setup the command object comm.Connection = conn comm.CommandType = CommandType.StoredProcedure comm.CommandText = "AddAudit" Dim startDateParam As New SqlClient.SqlParameter( _ "@startDate", SqlDbType.DateTime) Dim endDateParam As New SqlClient.SqlParameter( _ "@endDate", SqlDbType.DateTime) Dim resultParam As New SqlClient.SqlParameter( _ "@result", SqlDbType.Int) Dim methodNameParam As New SqlClient.SqlParameter( _ "@methodName", SqlDbType.NVarChar, 100) Dim otherDataParam As New SqlClient.SqlParameter( _ "@otherData", SqlDbType.NVarChar, 500) startDateParam.Value = m_startTime endDateParam.Value = m_endTime resultParam.Value = m_callResult methodNameParam.Value = m_methodName otherDataParam.Value = m_otherData ' Add the parameters to the command object. comm.Parameters.Add(startDateParam) comm.Parameters.Add(endDateParam) comm.Parameters.Add(resultParam) comm.Parameters.Add(methodNameParam) comm.Parameters.Add(otherDataParam) ' Execute the query. No results come back. comm.ExecuteNonQuery() ' Clean up conn.Close() Catch ex As Exception Trace.WriteLine(ex.ToString()) ' This code will throw an exception of its own ' if the default Web user does not have permission ' to write to a log file. Dim log As New System.Diagnostics.EventLog( _ "AuditLog", ".", "AuditLogError") log.WriteEntry( _ "An exception was caught at " & _ DateTime.Now.ToString() & vbCrLf & _ "Exception details: " & ex.ToString()) log.Dispose() End Try End Sub End Class End Namespace |
You will notice that the class is in its own namespace. I did this to help prevent name collisions with other classes. This code might get modified and reused quite a bit. If you modify this code, make sure to update the namespace to something appropriate for your Web site.
With a way to store the data, we now need to write the custom SOAP attribute. (Chapter 4, “Using Attributes to Shape the WSDL and XML,” covered the particulars of custom SOAP attributes.) This particular attribute will allow a user to audit any individual Web Method. The first class we need to implement inherits from SoapExtensionAttribute and is named AuditAttribute. This class, shown in Listing 5.5, allows the user of the class to set custom data through the otherData property.
Imports System.Web.Services Imports System.Web.Services.Protocols Namespace com.scottseely <AttributeUsage(AttributeTargets.Method)> _ Public Class AuditAttribute Inherits SoapExtensionAttribute ' Stores the priority for the class Private m_priority As Integer Private m_otherData As String = "" ' Returns the type that inherits from ' SoapExtension Public Overrides ReadOnly Property ExtensionType() As Type Get Return GetType(AuditExtension) End Get End Property ' Stores the Priority as set in the config file ' and returns that value on demand. Public Overrides Property Priority() As Integer Get Return m_priority End Get Set(ByVal Value As Integer) m_priority = Value End Set End Property ' Store the random data as requested by the ' user of the attribute. Public Property otherData() As String Get Return m_otherData End Get Set(ByVal Value As String) m_otherData = Value End Set End Property End Class End Namespace |
Now comes the part that does the work of auditing the Web Method—AuditExtension. It derives from SoapExtension and does most of the work in the ProcessMessage override. This class uses the AuditEntry class to mark various events in the call of the Web Method as well as store information discovered about the method being called. The start time of the call is noted in the BeforeDeserialize stage before the Web Method itself gets interpreted. After interpreting the message but before calling the method (the AfterDeserialize stage), the attribute pulls out the method name and stores that. Then, after the method has executed and the response has been created, the AfterSerialize stage checks for any faults. If a fault did occur, the cause of the fault is noted in the otherData member of the AuditEntry instance and the method checks to see if the client or server is responsible for the fault. Regardless of success or failure, the processing for the stage finishes by noting the end time. The AuditEntry instance then saves itself to the database and auditing for the method is complete. Listing 5.6 shows the code for the AuditExtension class.
Imports System.Web.Services Imports System Imports System.Web.Services.Protocols Imports System.IO Imports System.Xml Namespace com.scottseely Public Class AuditExtension Inherits SoapExtension Private m_auditEntry As AuditEntry ' We don't manipulate the stream. ' Just throw it back at the caller. Public Overrides Function ChainStream( _ ByVal stream As Stream) As Stream Return stream End Function ' Both GetInitializer overrides are present but do nothing. Public Overloads Overrides Function GetInitializer( _ ByVal methodInfo As LogicalMethodInfo, _ ByVal attribute As SoapExtensionAttribute) As Object Dim theAttr As AuditAttribute = attribute Return theAttr.otherData End Function Public Overloads Overrides Function GetInitializer( _ ByVal WebServiceType As Type) As Object ' No initializer used. By default, this returns Nothing m_auditEntry.otherData = "What the heck2" 'theAttr.otherData Return "No special data set" End Function ' Implemented because it has to be but does nothing. Public Overrides Sub Initialize(ByVal initializer As Object) m_auditEntry.otherData = CStr(initializer) End Sub ' Handle any chaining of the message between old and new. ' Besides that, manipulate the stream as needed Public Overrides Sub ProcessMessage(ByVal message As SoapMessage) Select Case message.Stage Case SoapMessageStage.BeforeSerialize Case SoapMessageStage.AfterSerialize m_auditEntry.endTime = DateTime.Now If (message.Exception Is Nothing) Then m_auditEntry.callResult = CallResult.Success Else m_auditEntry.otherData = _ message.Exception.ToString() If (message.Exception.Code Is _ SoapException.ClientFaultCode) Then m_auditEntry.callResult = _ CallResult.ClientFailure Else m_auditEntry.callResult = _ CallResult.ServerFailure End If End If m_auditEntry.Save() Case SoapMessageStage.BeforeDeserialize m_auditEntry.startTime = DateTime.Now Case SoapMessageStage.AfterDeserialize m_auditEntry.methodName = _ message.MethodInfo.Name Case Else Throw New Exception("invalid stage") End Select End Sub Public Sub New() m_auditEntry = New AuditEntry() End Sub End Class End Namespace |
To use the attribute, just apply to a Web Method and you are ready to go. Listing 5.7 shows a couple of Web Methods that use the attribute to implement logging with just one line of code.
<WebMethod(), _ Audit.com.scottseely.Audit(otherData:="This is a test")> _ Public Function HelloWorld() As String Return "Hello World!" End Function <WebMethod(), _ Audit.com.scottseely.Audit(otherData:="Another method")> _ Public Function AnotherMethod() As String Return "Yet another method" End Function |
The Web Service and a test application are included in the sample files on the companion Web site for you to see how everything works. The Web Service is named AuditTestService and the console application is named AuditTestConsole. Auditing is an often overlooked part of developing a Web Service. I hope the sample code here will help you add this basic functionality to your own Web Services.