The service solves a simple problem - how to monitor the execution time of service invocations in a production environment. It allows to monitor a a user-defined list of services and tresholds which affects the trace level of the logger being used to write the performance data.
During the execution the service captures the following information for producing a meaning log
Item | Description |
---|---|
Transaction ID (TID) | the number of times the invocationDepth was zero |
Invocation ID (IID) | the current number of inovking a service method |
InvocationDepth (ID) | the service invocation depth, e.g a value of "1" that the currently invoked service method was invoked by another service. A value of "0" indicates that the service method was directly invoked from the caller therefore starting a new transaction |
Mode (M) |
the invocation mode of the interceptor
|
ServiceName | the shorthand of the service being invoked |
ServiceMethod | the name of the service method being invoked |
Millis | the execution time in milliseconds |
Method Signature | the name of the executing thread |
Looking at the following example you see that
TID IID ID M ServiceName ServiceMethod Millis 18 28 0 1 SignatureService sign 140 18 29 1 1 PdfSignatureService isSupported 0 18 30 1 1 PdfSignatureService sign 140 18 31 2 1 CommandDispatcher exists 0 18 32 2 1 ResourceManagerService exists 0 18 33 2 1 ResourceManagerService exists 0 18 34 2 1 ResourceManagerService read 0 18 35 2 1 PKCS12KeyStore getCertificateEntry 0
Item | Datatype | Cardinality | Description |
---|---|---|---|
isEnabled | Boolean | [0|1] | Turn the interceptor. If no value is supplied then "false" is used thereby disabling all interceptor invocations. |
tresholds | Tree | [0|1] | Contains a list of mappings from execution time to tracelevel |
tresholds/debug | Integer | [0|1] | The minimum exeuction time for debug output |
tresholds/info | Integer | [0|1] | The minimum exeuction time for info output |
tresholds/warn | Integer | [0|1] | The minimum exeuction time for warn output |
tresholds/error | Integer | [0|1] | The minimum exeuction time for error output |
tresholds/fatal | Integer | [0|1] | The minimum exeuction time for fatal output |
services | Tree | [0|1] | Contains a list of services to be monitored. |
services/service@name | String | [1..n] | The name of an individual service to be monitored. |
<role name="org.apache.fulcrum.yaafi.interceptor.performance.PerformanceInterceptorService" shorthand="PerformanceInterceptorService" default-class="org.apache.fulcrum.yaafi.interceptor.performance.PerformanceInterceptorServiceImpl" logger="performance" />
The following Log4J configuration defines a custom appender for the PerformanceInterceptorService. For the layout we just add a timestamp since we produce a CSV file to be analyzed with EXCEL or your tool of choice
# # Custom logfiles # log4j.category.yaafi.performance = DEBUG, performance log4j.additivity.yaafi.performance = false # # Performance Appender # log4j.appender.performance = org.apache.log4j.FileAppender log4j.appender.performance.file = ./temp/performance.csv log4j.appender.performance.layout = org.apache.log4j.PatternLayout log4j.appender.performance.layout.conversionPattern = %d;%m%n log4j.appender.performance.append = true
Monitor all exection times
<PerformanceInterceptorService> <isEnabled>true</isEnabled> <tresholds> <debug millis="0"/> <info millis="100"/> <warn millis="500"/> <error millis="1000"/> <fatal millis="5000"/> </tresholds> <services> <service name="*"/> </services> </PerformanceInterceptorService>