I have a set of WCF SOAP web services. A few of the service operations allows users to submit data. I want to log the payload from these requests to a SQL Server database. For clients that just read data, I only want to log simple metadata.
I have a class that implements the IParameterInspector interface. All service operations requests are logged in the BeforeCall method: time of request, operation name, userid and target endpoint.
public class LogParameterInspector : IParameterInspector
{
private static WebServiceLog WebServiceLog = WebServiceLog.GetInstance();
private bool IsOperationIgnorable(string operationName)
{
//Ignore GETs for service metadata
return string.Equals(operationName, "get", StringComparison.InvariantCultureIgnoreCase);
}
public void AfterCall(string operationName, object[] outputs, object returnValue, object correlationState)
{
if (IsOperationIgnorable(operationName))
return;
SsnWebServiceContext.Current.Response.CreatedDate = DateTime.Now;
//Calls stored procedure
WebServiceLog.LogServerResponseToDb(SsnWebServiceContext.Current.Response);
}
public object BeforeCall(string operationName, object[] inputs)
{
if (IsOperationIgnorable(operationName))
return null;
SsnWebServiceContext.Current.Request.CreatedDate = DateTime.Now;
SsnWebServiceContext.Current.Request.OperationName = operationName;
foreach (var item in inputs)
{
if (item == null) continue;
if (item.GetType().GetInterfaces().Any(x => x.IsGenericType && x.GetGenericTypeDefinition() == typeof(IRequest<>)))
{
var header = item
.GetType()
.GetProperties()
.Single(p => p.Name == "Header")
.GetValue(item, null) as IRequestHeader;
SsnWebServiceContext.Current.Request.UserIdentification = header?.UserName;
}
}
//Calls stored procedure
WebServiceLog.LogClientRequestToDb(SsnWebServiceContext.Current.Request);
return null;
}
}
The message payload is explicitly logged in the few service operations that require it. (Calling the same stored procedure as in BeforeCall. The procedure checks if a record with the given GUID already exists, and if so, updates it).
I have a class that implements IExtension<OperationContext>. This class gives me access to request/response data through the lifetime of a request.
public class SsnWebServiceContext : IExtension<OperationContext>
{
//Helper property for syntax purposes
public static SsnWebServiceContext Current => OperationContext.Current.Extensions.Find<SsnWebServiceContext>();
//Called when extension is added to OperationContext. Useful for initializing stuff.
public void Attach(OperationContext owner)
{
var tmp = Guid.NewGuid();
Request = Request ?? new ClientRequest();
Request.SetReadOnlyGuid(tmp);
Response = Response ?? new ServerResponse();
Response.SetReadOnlyGuid(tmp);
}
//Called when extension is removed from OperationContext. Use for for cleanup.
public void Detach(OperationContext owner)
{
}
public ClientRequest Request { get; set; }
public ServerResponse Response { get; set; }
}
My custom context is added to OperationContext through a class that implements IDispatchMessageInspector. This is also where I create a copy of the message stream for future reference.
public class ContextDispatchMessageInspector : IDispatchMessageInspector
{
public object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext)
{
using (var buffer = request.CreateBufferedCopy(int.MaxValue))
{
OperationContext.Current.Extensions.Add(new SsnWebServiceContext
{
Request = new ClientRequest
{
Message = buffer.CreateMessage(),
TargetRole = OperationContext.Current.IncomingMessageHeaders?.To?.ToString()
}
});
request = buffer.CreateMessage();
}
return null; //Correlation state passed to BeforeSendReply
}
public void BeforeSendReply(ref Message reply, object correlationState)
{
OperationContext.Current.Extensions.Remove(SsnWebServiceContext.Current);
}
}
All my endpoints are configured for basicHttpBinding with the following settings:
<bindings>
<basicHttpBinding>
<binding name="SSNBinding" maxBufferSize="2147483647" maxReceivedMessageSize="2147483647" >
<security mode="None"></security>
</binding>
</basicHttpBinding>
</bindings>
Problem:
The logging works fine, except for larger messages. When I try to view some of the XML messages in SSMS, I get the following error:
If I copy the XML content into a text editor, it's clear that the entire message has not been logged. I have found that this occurs only for requests where users are uploading files bigger than around 2MB. Files are uploaded as base64 encoded strings, and the logged XML content is truncated somewhere in the middle of the encoded string.
Weirdly (to me) the file seems to have been transferred successfully, even if it hasn't been logged completely. I've reproduced the behaviour locally, using SOAP UI and base64 encoding a large image: The request took a while (timed out after 1 minute in SOAP UI), but still completed succesfully some time later; I downloaded and viewed the image, and it was not corrupt. I got the same result with a large Word document.
Any suggestions on what I can do to prevent my logs from being truncated would be highly appreciated!