Logging and Rewriting Service Calls
I love web services. I love how easy it is to wire up a JavaScript client either through jQuery or through a ServiceProxy. I love how I can point a .net client at a service, and I get strongly typed command parameters. And my latest love of asmx services in C# is the SoapExtension. A SoapExtension is a class that allows you to inspect outgoing or incoming services to get at the data involved. I use them for logging service calls (frequency, duration, errors), and for rewriting output (fixed a “double html encoded” bug, remove whitespace, rewrite SoapFaults, etc).
The technique is incredibly awesome, and I can’t claim original ownership, but I can claim excellent results. A few simple steps:
Create a class that derives from SoapExtension.
Override ProcessMessage, handling the SoapMessage’s Stage that you’re interested in.
Add either a web.config entry (to handle all inbound and outbound service calls), or put an attribute on each WebMethod you want to track.
Voila! You’ve got a soap extension.
Here’s my ExampleSoapExtension (business logic replaced with TODO to keep it simple):
namespace ExampleNamespace {
#region using
using System;
using System.Data.Linq;
using System.IO;
using System.Linq;
using System.Text.RegularExpressions;
using System.Threading;
using System.Web;
using System.Web.Services.Protocols;
#endregion
public class ExampleSoapExtension : SoapExtension {
private Stream originalStream; // The original stream
private Stream internalStream; // Our new stream we chained into place
public ExampleSoapExtension() {
}
// Called the first time the Web service is used if configured with a config file
public override object GetInitializer( Type t ) {
return typeof( ExampleSoapExtension );
}
// Called the first time the Web service is used if configured with an attribute
public override object GetInitializer( LogicalMethodInfo methodInfo, SoapExtensionAttribute attribute ) {
return attribute;
}
// Called each time the Web service is used and gets passed the data from GetInitializer() method
public override void Initialize( object initializer ) {
// Get the attribute here and pull whatever you need off it.
//ExampleSoapExtensionAttribute attr = initializer as ExampleSoapExtensionAttribute;
}
// The ChainStream() method gives us a chance to grab the SOAP messages as they go by
public override Stream ChainStream( Stream stream ) {
// Save the original stream
originalStream = stream;
// Create and return our own in its place
internalStream = new MemoryStream();
return internalStream;
}
// The ProcessMessage() method is called between each step in the server-side process
public override void ProcessMessage( SoapMessage message ) {
switch ( message.Stage ) {
case SoapMessageStage.BeforeDeserialize:
// About to handle incoming SOAP request
string requestContent = StreamToText( this.originalStream, false );
WriteIncomingToLog( message, requestContent );
TextToStream( requestContent, this.internalStream, true );
break;
case SoapMessageStage.AfterDeserialize:
// incoming SOAP request has been deserialized
WriteInputToLog( message );
break;
case SoapMessageStage.BeforeSerialize:
// About to prepare outgoing SOAP Response
WriteOutputToLog( message );
break;
case SoapMessageStage.AfterSerialize:
// outgoing SOAP response is ready to go
string responseContent = null;
if ( message.Exception != null ) {
// Rewrite soap fault as valid soap message with internal error code
// Though it might be nice to do this before serialization, we can't inject our own return value easily
responseContent = RewriteError( message );
} else {
responseContent = StreamToText( this.internalStream, true );
}
WriteOutgoingToLog( message, responseContent );
TextToStream( responseContent, this.originalStream, false );
break;
default:
throw new Exception( “invalid stage” );
}
}
private static string StreamToText( Stream stream, bool rewindBefore ) {
if ( rewindBefore ) {
stream.Position = 0;
}
TextReader reader = new StreamReader( stream );
string content = reader.ReadToEnd();
return content;
}
private static void TextToStream( String text, Stream stream, bool rewindAfter ) {
TextWriter writer = new StreamWriter( stream );
writer.Write( text );
writer.Flush();
if ( rewindAfter ) {
stream.Position = 0;
}
}
#region WriteIncomingToLog
///
/// Write the incoming stream content to the logs
///
private void WriteIncomingToLog( SoapMessage Message, string Content ) {
HttpRequest req = HttpContext.Current.Request;
// TODO: Log various parameters here including the incoming xml and start date
}
#endregion
#region WriteInputToLog
private void WriteInputToLog( SoapMessage Message ) {
ServiceInputObject input = null;
if ( Message.MethodInfo.InParameters.Length > 0 ) {
try {
input = Message.GetInParameterValue( 0 ) as ServiceInputObject;
} catch ( Exception /ex/ ) {
input = null;
}
}
if ( input != null ) {
// TODO: Log the message details
}
}
#endregion
#region WriteOutputToLog
private void WriteOutputToLog( SoapMessage Message ) {
if ( Message.Exception != null ) {
// The return object doesn't exist because an exception was thrown
// RewriteError will create one
return;
}
ServiceOutputObject output = null;
if ( Message.MethodInfo != null && Message.MethodInfo.ReturnType != null && Message.MethodInfo.ReturnType.FullName != “System.Void” ) {
output = Message.GetReturnValue() as ServiceOutputObject;
} else {
output = null;
}
if ( output != null ) {
// TODO: Log the output details
}
}
#endregion
#region WriteOutgoingToLog
///
/// Write the message in the stream to the log4net log
///
private void WriteOutgoingToLog( SoapMessage Message, string Content ) {
string outboundData = GetStreamText( StreamToLog );
// TODO: Log the outgoing xml string and end date
}
#endregion
#region CaptureError
///
/// Insure the exception is logged
///
private Stream CaptureError( SoapMessage Message, Stream stream ) {
// Log the exception
Exception ex = Message.Exception;
while ( ex != null && ex.InnerException != null && ex.GetType() == typeof( SoapException ) ) {
ex = ex.InnerException;
}
// TODO: Log the exception
// TODO: Form the output reply and serialize it
string soapMessage = null;
// Now send this as the out stream instead of the soap:Fault stream we had before
MemoryStream outStream = new MemoryStream();
TextWriter writer = new StreamWriter( outStream );
writer.WriteLine( soapMessage );
writer.Flush();
outStream.Position = 0;
// And send the 200 status instead of 400
//HttpContext.Current.Response.StatusCode = 200;
// Here's the content to send instead of what ever you had
return outStream;
}
#endregion
}
[AttributeUsage( AttributeTargets.Method )]
public class ExampleSoapExtensionAttribute : SoapExtensionAttribute {
public ExampleSoapExtensionAttribute() {
this.Priority = 1;
}
public override int Priority { get; set; }
// Specifies the class of the SOAP Extension to use with this method
public override Type ExtensionType {
get { return typeof( ExampleSoapExtension ); }
}
}
}
My current quest: how do I do this in WCF? Is there such a thing as a “message watcher” or “handler” or “pipeline interceptor”? All these terms on Google come up blank. With WCF’s new configuration-less services and MS’s desire to move on past asmx, WCF seems a foregone conclusion. For me, this is the last hurdle.
Rob