WCF message logging - add filters with XPath queries

Question

I have a WCF service with the following contract:

[ServiceContract(Namespace="http://myNamespace.org/")]
public interface IMyService
{
    [OperationContract]
    string Invert(string s);

    [OperationContract]
    string ToUpper(string s);
}

Clients call both methods, Invert and ToUpper. Imagine I want to use message logging, but the only method I'm interested in is ToUpper as the other method is heavily used and logging all the messages would blow the log ;)

Here, I read how to filter the messages that are written into the log. But I must be doing something wrong as my log remains empty... My config looks like this

<system.serviceModel>
  ...
  <diagnostics>
    <messageLogging logEntireMessage="true" logMessagesAtServiceLevel="false" logMalformedMessages="true" logMessagesAtTransportLevel="true">
      <filters>
        <add xmlns:soap="http://www.w3.org/2003/05/soap-envelope" xmlns:a="http://www.w3.org/2005/08/addressing">/soap:Envelope/soap:Header/a:Action[starts-with(text(),'http://myNamespace.org/IMyService/ToUpper')]</add>
      </filters>
    </messageLogging>
  </diagnostics>

</system.serviceModel>

<system.diagnostics>
  <sources>
    <source name="System.ServiceModel.MessageLogging">
      <listeners>
        <add name="ServiceModelTraceListener" />
      </listeners>
    </source>
  </sources>
  <sharedListeners>
    <add initializeData="LogServer.svclog" type="System.Diagnostics.XmlWriterTraceListener" name="ServiceModelTraceListener" />
  </sharedListeners>
  <trace autoflush="true" />
</system.diagnostics>

If I apply this filter, there won't go a single message into the log... So what am I doing wrong regarding the linked example above?

Without the filter the xml trace of a default message (method ToUpper invoked with string parameter hello) looks like this:

<E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
  <System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
    <EventID>0</EventID>
    <Type>3</Type>
    <SubType Name="Information">0</SubType>
    <Level>8</Level>
    <TimeCreated SystemTime="2011-05-27T17:53:53.9908714Z" />
    <Source Name="System.ServiceModel.MessageLogging" />
    <Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
    <Execution ProcessName="WcfLoggingTest.Host.vshost" ProcessID="4324" ThreadID="12" />
    <Channel />
    <Computer>MY-Machine</Computer>
  </System>
  <ApplicationData>
    <TraceData>
      <DataItem>
        <MessageLogTraceRecord Time="2011-05-27T19:53:53.9908714+02:00" Source="TransportReceive" Type="System.ServiceModel.Channels.BufferedMessage" xmlns="http://schemas.microsoft.com/2004/06/ServiceModel/Management/MessageTrace">
          <HttpRequest>
            <Method>POST</Method>
            <QueryString></QueryString>
            <WebHeaders>
              <VsDebuggerCausalityData>uIDPozEtlPQCjkhCodYdPWh6joUAAAAAamILDP7v3kG5sY6zKsB7HPPiLBWr+AVGmfFDQbk8GYAACQAA</VsDebuggerCausalityData>
              <SOAPAction>"http://myNamespace.org/IMyService/ToUpper"</SOAPAction>
              <Content-Length>157</Content-Length>
              <Content-Type>text/xml; charset=utf-8</Content-Type>
              <Accept-Encoding>gzip, deflate</Accept-Encoding>
              <Expect>100-continue</Expect>
              <Host>localhost:8731</Host>
            </WebHeaders>
          </HttpRequest>
          <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
            <s:Header>
              <To s:mustUnderstand="1" xmlns="http://schemas.microsoft.com/ws/2005/05/addressing/none">http://localhost:8731/Design_Time_Addresses/MyService/</To>
              <Action s:mustUnderstand="1" xmlns="http://schemas.microsoft.com/ws/2005/05/addressing/none">http://myNamespace.org/IMyService/ToUpper</Action>
            </s:Header>
            <s:Body>
              <ToUpper xmlns="http://myNamespace.org/">
                <s>hello</s>
              </ToUpper>
            </s:Body>
          </s:Envelope>
        </MessageLogTraceRecord>
      </DataItem>
    </TraceData>
  </ApplicationData>
</E2ETraceEvent>

Update: For for every body who's interested in the solution, I finally got it working with jasso's help, thanks:

<add xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:a="http://schemas.microsoft.com/ws/2005/05/addressing/none">/soap:Envelope/soap:Header/a:Action[starts-with(text(),'http://myNamespace.org/IMyService/ToUpper')]</add>

I then edited my Interface and added the methods Method1 till Method3. My goal was then to log everything except the messages related to Method1 and Method3. I did this with the following filter:

<add xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:a="http://schemas.microsoft.com/ws/2005/05/addressing/none">/soap:Envelope/soap:Header/a:Action[starts-with(text(),'http://myNamespace.org/IMyService/Method1')=false() and starts-with(text(),'http://myNamespace.org/IMyService/Method3')=false()]</add>

This way, only the messages related to Invert, ToUpper and Method2 are logged.

It may be a cleaner approach to handle this with two seperate filters, but for the moment I'm quite happy with this.

Answer 1

You are using a wrong namespace for the Action element in your XPath expression

You have

xmlns:a="http://www.w3.org/2005/08/addressing"
... /a:Action[starts-with ...

and the document has

<Action s:mustUnderstand="1" xmlns="http://schemas.microsoft.com/ws/2005/05/addressing/none">

So the namespaces differ, because Action element has a default namespace definition attached to it.

Also your XPath is searching for a soap:Envelope root element because your expression starts with a /. I'm not familiar with the framework, it might select a subtree from your example XML (the soap content) and then apply the XPath filter. If this is not the case and your XPath should produce a match on that given XML document, then you should start the expression with // or with a path to soap:Envelope element (like /*/*/*/*/*/soap:Envelope). Using // operator in the beginning is inefficient since it requires going through all the nodes in the whole document.

Answer 2

Very thanks for the useful information!

According to my own study, to perform the filtering successfully, these key points must be enforced as well:

1. do not start the XPath expression with double "/", else the filtering will not work at all. Although this double "/" is correct regarding to XPath syntax (the same as what jasso pointed at May 27 23:06, 2011).
2. do not rely on the WCF Configuration Edit tool to choose the alias for the involved xml namespace. Till now it is found that "s12" does not work, but "s" or "s1a" is OK (Maybe it is a bug done by Microsoft, I am not sure).