tomcattomcat8access-logtomcat-valve

My custom tomcat valve is not being intercepted

Here is the custom valve class that I wrote.. All it does is to mask password before logging to access log files ...

package com.test;

import org.apache.catalina.valves.AccessLogValve;

public class FilteredAccessLogValve extends AccessLogValve {

    public void log(String message) {
        message = message.replaceAll("password=[^&]*", "password=***");
        super.log(message);
    }
}

I build this as a value-lib.jar and copied to $TOMCAT_HOME/lib folder.

Then I customized the loggin entry in server.xml as follows under entry localhost

  <Host name="localhost"  appBase="webapps"
        unpackWARs="true" autoDeploy="true">

    <!-- SingleSignOn valve, share authentication between web applications
         Documentation at: /docs/config/valve.html -->
    <!--
    <Valve className="org.apache.catalina.authenticator.SingleSignOn" />
    -->

    <!-- Access log processes all example.
         Documentation at: /docs/config/valve.html
         Note: The pattern used is equivalent to using pattern="common" -->
    <Valve className="com.test.FilteredAccessLogValve" directory="logs"
           prefix="localhost_access_log" suffix=".txt"
           pattern=" com.test.FilteredAccessLogValve %{X-Forwarded-For}i %h %l %S %u %t '%r' %s %b %D"/>        

           <!-- pattern="%h %l %u %t &quot;%r&quot; %s %b" /-->

  </Host>

Now, all my log requests are logged properly like this in localhost_access_log.2018-02-12.txt file

com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:13:49 +0530] 'GET / HTTP/1.1' 200 11452 362
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:13:56 +0530] 'GET /manager/html HTTP/1.1' 401 2536 45
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:14:11 +0530] 'GET /host-manager/html HTTP/1.1' 401 2098 16
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:22:21 +0530] 'GET /host-manager/html HTTP/1.1' 401 2098 132
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:22:22 +0530] 'GET /favicon.ico HTTP/1.1' 200 21630 9
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:24:53 +0530] 'GET / HTTP/1.1' 200 11452 212
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:25:04 +0530] 'GET /?password=123 HTTP/1.1' 200 11452 10
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:10:46:53 +0530] 'GET /ROOT/ HTTP/1.1' 404 1075 52

The problem that i face is when I pass say a parameter like password=123 to the URL like this say http://localhost:8080?password=123.

I expect that to be logged as 

com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:11:01:02 +0530] 'GET /?password=*** HTTP/1.1' 200 11452 14

where as it is now logged as 

com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - - - [12/Feb/2018:11:01:02 +0530] 'GET /?password=123 HTTP/1.1' 200 11452 14

there is no masking happening for the password value.. I tried to put a debugger in eclipse for the jar through Remote Java application with Tomcat being started in "jpda start" mode.

There I could not see the control being transferred to this class at all..

So, I'm little confused on how it works because it takes the log formatting from the XML config that I added to server.xml but in the same XML config I mentioned the class name as "com.test.FilteredAccessLogValve" but that't not being picked

Solution

  • At last I found the solution.. Problem was that I use tomcat 7 jar in development and testing the solution in tomcat 8.5 implementation..

    Tomcat has changed the method signature for log() call in "AccessLogValve" class between these 2 versions. Earlier it was 

    public void log(String message);

    now its been modified as 

    public void log(CharArrayWriter message);

    and hence my custom implemetation has been changed to 

    package com.test;

import org.apache.catalina.valves.AccessLogValve;

public class FilteredAccessLogValve extends AccessLogValve {

    public void log(CharArrayWriter message) {
        String mymessage = message.toString();
        if(mymessage.toLowerCase().contains("password=")) {
            mymessage = mymessage.replaceAll("password=[^&]*", "password=***");

            CharArrayWriter maskedMessage = new CharArrayWriter(1024);
            try {
                maskedMessage.write(mymessage);
            } catch (IOException e) {
                // TODO Auto-generated catch block
                e.printStackTrace();
            }
            super.log(maskedMessage);
        } else {
            super.log(message);
        }
    }
}

    As I overridden the proper method, now the logs for this http://localhost:8080/manager/html/list?password=123 calls are masked properly as shown below

    com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - C71654B9F585F83AAF6E9A4233BD7D8B tomcat [12/Feb/2018:13:01:06 +0530] 'GET /manager/html/list?password=***
com.test.FilteredAccessLogValve - 0:0:0:0:0:0:0:1 - C71654B9F585F83AAF6E9A4233BD7D8B tomcat [12/Feb/2018:13:01:11 +0530] 'GET /manager/html/list?password=***