TraceInterceptor enhancements [SPR-601]

[spring-projects-issues]

Claus Ibsen opened SPR-601 and commented

I forked the org.springframework.aop.interceptors.TraceInterceptor as I needed several added functionality. I ended up adding a few more features and made it customizable so I could contribute it back to the Spring team.

I have attached a modified version of the TraceInterceptor.java with these enhancements:

• possible to customize output formating of ENTER and EXIT messages
• possible to output elapsed time
• possible to output method arguments
• possible to use dynamic logger name (using the classname of the method invocation = just as if you had written to log code in the class itself. See example)

Using the dynamic logname makes it possible to output logs as:

http8080-Processor4 07 jan 2005 11:22:58 DEBUG dk.netfragt.pbs.NetfragtPBSWebService - ENTER - accepterFaktura
dk.netfragt.pbs.NetfragtPBSWebService - EXIT - accepterFaktura. Time = 1656 msec.

Instead of the default:

http8080-Processor4 07 jan 2005 11:19:43 DEBUG org.springframework.aop.interceptor.TraceInterceptor - Entering method accepterFaktura in class [dk.netfragt.pbs.NetfragtPBSWebService]

And with the method arguments you can see what has been passed in as arguments (in this example 77777):

http8080-Processor4 07 jan 2005 11:19:43 DEBUG org.springframework.aop.interceptor.TraceInterceptor - Entering method accepterFaktura(77777) in class [dk.netfragt.pbs.NetfragtPBSWebService]

And you can change the formatting of the message using java.text.Format with {0} placeholders. The defaults are:

private String enterMessage = "Entering method {1}{2} in class [{0}]";
private String exitMessage = "Exiting method {1}{2} in class [{0}]";

You can customize this in the spring .xml configuration:

<bean id="traceInterceptor" class="org.springframework.aop.interceptor.TraceInterceptor">
	<property name="elapsedTime"><value>true</value></property>
	<property name="arguments"><value>true</value></property>
	<property name="dynamicLogName"><value>true</value></property>
	<property name="enterMessage"><value>ENTER - {1}{2}</value></property>
	<property name="exitMessage"><value>EXIT  - {1}{2}</value></property>
</bean>

Using the above will output:

http8080-Processor4 07 jan 2005 11:22:58 DEBUG dk.netfragt.pbs.NetfragtPBSWebService - ENTER - accepterFaktura(676767)
http8080-Processor4 07 jan 2005 11:23:00 DEBUG dk.netfragt.pbs.NetfragtPBSWebService - EXIT - accepterFaktura(676767). Time = 1656 msec.

As the example above illustrates that using dynamicLogName and customizing the log message it is possible to change it radically.

I hope the Spring team could accept these changes as the default version is the same as the existing one.

---

Affects: 1.1.3

Attachments:

• TraceInterceptor.java (7.50 kB)
• TraceInterceptor.java (5.55 kB)

Issue Links:

• [PATCH] Enhancements to TraceInterceptor [SPR-860] #5586 [PATCH] Enhancements to TraceInterceptor ("is duplicated by")

[spring-projects-issues]

Claus Ibsen commented

The placeholders are documented in the class javadoc

/**

• Simple AOP Alliance MethodInterceptor that can be introduced in a chain
• to display verbose trace information about intercepted method invocations
• with method entry and method exit info using Commons Logging at DEBUG level.

<p/>

• It is possible to enable output of elapsed time and/or method arguments by setting
• its corresponding properties.

<p/>

• Another feature is to use either a static logger or a dynamic log based on the method
• invocation classname.

<p/>

• The log messages itself can also be formatted using the properties for enter and exit message.
• The messages are per default:
• <br/><code>Entering method {1}{2} in class [{0}]</code>
• <br/><code>Exiting method {1}{2} in class [{0}]</code>

<br/>

• <br/>Placeholder {0} is the classname.
• <br/>Placeholder {1} is the methodname.
• <br/>Placeholder {2} is the method arguments.

[spring-projects-issues]

Claus Ibsen commented

The source file

[spring-projects-issues]

Claus Ibsen commented

I don't need my name in the @author tag in the javadoc if the code is accepted.

[spring-projects-issues]

Claus Ibsen commented

This is a new version of the TraceInterceptor - mind the package name in the top.

[spring-projects-issues]

Claus Ibsen commented

I rewoked the interceptor.

• fixing a bug using the correct logging category for the dynamic logger.
• default debug messages are now excatly as the original spring traceinterceptor using ' ' around the method name invoced.
• new feature to output parameter types
• polishing javadoc

• <br/>Placeholder {0} is the classname.
• <br/>Placeholder {1} is the methodname.
• <br/>Placeholder {2} is the method arguments.
• <br/>Placeholder {3} is the method parameter types as classnames using their shortname.

[spring-projects-issues]

Claus Ibsen commented

Example from my console:

2005-04-04 22:22:06,687 DEBUG [org.dummy.MyDummyBean] - ENTER - foo()
foo called(): age=31
2005-04-04 22:22:06,687 DEBUG [org.dummy.MyDummyBean] - EXIT - foo()
2005-04-04 22:22:06,687 DEBUG [org.dummy.MyDummyBean] - ENTER - bar(Claus,null,26)
bar called() with name=Claus, date=null, newAge=26
2005-04-04 22:22:06,687 DEBUG [org.dummy.MyDummyBean] - EXIT - bar(String,Date,int)

Using this spring configuration:
<bean id="dummyBean" class="org.springframework.aop.framework.ProxyFactoryBean">
<property name="target">
<bean id="dummyBeanTarget" class="org.dummy.MyDummyBean">
<property name="age">
<value>31</value>
</property>
</bean>
</property>
<property name="interceptorNames">
<list>
<value>traceInterceptor</value>
</list>
</property>
</bean>

<bean id="traceInterceptor" class="org.dummy.TraceInterceptor">
    <property name="elapsedTime">
        <value>false</value>
    </property>
    <property name="arguments">
        <value>true</value>
    </property>
    <property name="parameterTypes">
        <value>true</value>
    </property>
    <property name="dynamicLogName">
        <value>true</value>
    </property>
    <property name="enterMessage">
        <value>ENTER - {1}{2}</value>
    </property>
    <property name="exitMessage">
        <value>EXIT - {1}{3}</value>
    </property>
</bean>

[spring-projects-issues]

Claus Ibsen commented

The same example again using the same configuration as the original Spring TraceInterceptor.

2005-04-04 22:26:57,078 DEBUG [org.dummy.TraceInterceptor] - Entering method 'foo' in class [org.dummy.MyDummyBean]
foo called(): age=31
2005-04-04 22:26:57,078 DEBUG [org.dummy.TraceInterceptor] - Exiting method 'foo' in class [org.dummy.MyDummyBean]
2005-04-04 22:26:57,078 DEBUG [org.dummy.TraceInterceptor] - Entering method 'bar' in class [org.dummy.MyDummyBean]
bar called() with name=Claus, date=null, newAge=26
2005-04-04 22:26:57,078 DEBUG [org.dummy.TraceInterceptor] - Exiting method 'bar' in class [org.dummy.MyDummyBean]

<bean id="traceInterceptor" class="org.dummy.TraceInterceptor"/>
Note that org.dummy.TraceInterceptor is the packagename for the revoked version attached as file #2.

[spring-projects-issues]

Claus Ibsen commented

See also #5586

[spring-projects-issues]

Juergen Hoeller commented

See #5586