Logging in Apache CXF STS enhanced

This extension will be available in CXF release 2.7.6 which is not yet available. But you can run tests with the SNAPSHOT build till this version is released. Please provide feedback to the CXF mailing list.

Different logging frameworks (SLF4J, Log4J, Logback, JUL) can be used to log events for Apache CXF STS. The configuration allows to define which logger should log messages till to which log level. That works fine to drill down generic issues but it doesn't help too much to know whether a certain user could successfully log in or had any specific issues. Further, the WS-Trust interface is very generic. Therefore, the same user can request tokens but for different applications using different credential types. If a log in error occurs some context information is required to easily drill down user specific issues.

Based on the experience of a customer deployment, the following information is helpful to figure out how often a user requested a token and under which circumstances:

• AppliesTo
  For which application did the user request a token
• Source IP
  From which machine did the application request a token for a user
• Claims
  Which claims did the user request for an application
• Security Header
  How did the user try to log in (Username/password, Kerberos, X509, ...)
• Realm
  For which security domain did the user request a token
• etc.

All this information are available within the core classes of the STS and thus not customizable without patching these classes. The next release of CXF will provide a customizable logging/auditing functionality to fulfill various requirements.

Spring Eventing

The Spring framework provides an eventing mechanism which is designed for simple communication between Spring beans. Instead of introducing a new eventing mechanism to push data to a class which processes the data and writes it to a log file the new feature leverages the usage of the Spring framework in the CXF STS. How Spring eventing works is described on the following blog. If you don't want to delay STS related processing you can publish the events asynchronously which is described here.

CXF STS custom Application Events

Depending on the STS operation called, a different object with context information is created in the CXF STS. The following table summarizes the defined bindings in the WS-Trust specification, the CXF related context object as well a link with more information about this binding:

Binding	Context objcect	Spring Event	Documentation
Issue	TokenProviderParameters	STSIssueSuccessEvent STSIssueFailureEvent	blog
Validate	TokenValidatorParameters	STSValidateSuccessEvent STSValidateFailureEvent	blog
Cancel	TokenCancellerParameters	STSCancelSuccessEvent STSCancelFailureEvent	blog
Renew	TokenRenewerParameters	STSRenewSuccessEvent STSRenewFailureEvent	blog

The different binding implementations support the interface ApplicationEventPublisherAware thus they can publish events about a successful or failed request. You have to provide an implementation of ApplicationListener to listen to Spring Application Events. Due to the usage of generics you can specify which events you want to listen to. All the above STS specific events inherit the abstract class AbstractSTSEvent. If you want to listen to all STS events then you must provide an implementation like this:

public class AllSTSEventsListener implements ApplicationListener {
    @Override
    public void onApplicationEvent(AbstractSTSEvent event) {
        // do whatever you want here
    }
}

If you want to listen to all successful issue events you must use the generic STSIssueSuccessEvent. The STS provides the LoggerListener which listens to all STS events and uses the CXF Logging API to write the log message. All you have to do is configure the following bean in the STS application context configuration (ex. cxf-transport.xml):

<bean id="loggerListener" class="org.apache.cxf.sts.event.LoggerListener" />

If you want to configure another Application listeners, just add a bean configuration and you're done.

The LoggerListener is able to log the following context information:

• TIME
  Creation time of the event
• OPERATION
  STS binding/operation
• WS_SEC_PRINCIPAL
  Principal in WS-Security token
• STATUS
  Successful/failed request
• DURATION
  Processing time
• TOKENTYPE
  Token type requested (SAML 1.1, SAML 2.0, etc)
• REALM
  Security domain
• APPLIESTO
  Application for which token is requested
• CLAIMS
  Claims requested
• ACTAS_PRINCIPAL
  Principal of ActAs token
• ONBEHALFOF_PRINCIPAL
  Principal of On-Behalf-Of token
• VALIDATE_PRINCIPAL
  Principal of Validate token
• CANCEL_PRINCIPAL
  Principal of Cancel token
• RENEW_PRINCIPAL
  Principal of Renew token
• REMOTE_HOST
  Hostname/IP which requested the token
• REMOTE_PORT
  Source Port which requested the token
• URL
  STS URL used to request token

The LoggerListener provides the following properties to customize its behaviour:

Name	Type	Mandatory	Default	Description
logFieldname	Boolean	No	No	Should the fieldname be logged, ex. OPERATION=issue
dateFormat	String	No	getDateTimeInstance(DateFormat.SHORT, DateFormat.MEDIUM)	Format of the date
logLevel	String	No	FINE	Which log level should be used?
logStacktrace	Boolean	No	No	In case of an error, shall the stacktrace be logged?
fieldOrder	List<String>	No	TIME STATUS DURATION REMOTE_HOST REMOTE_PORT OPERATION URL REALM WS_SEC_PRINCIPAL ONBEHALFOF_PRINCIPAL ACTAS_PRINCIPAL VALIDATE_PRINCIPAL CANCEL_PRINCIPAL RENEW_PRINCIPAL TOKENTYPE APPLIESTO CLAIMS EXCEPTION	Order of context fields to be logged

If you want that all LoggerListener related log messages are written into a different file (ex. audit.log) I highly recommend to not use Java Util Logging as it's not so easy to configure a dedicated handler/appender for one logger.

1. Configure Log4J as the logging framework in CXF (see here)
2. Add the log4j dependency to your POM
3. Configure the logger and appender
   

   log4j.rootLogger=INFO, CONSOLE, LOGFILE
   log4j.logger.org.apache.cxf.sts.event.LoggerListener=DEBUG, AUDIT
   
   # CONSOLE is set to be a ConsoleAppender using a PatternLayout.
   log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
   log4j.appender.CONSOLE.Threshold=INFO
   log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
   log4j.appender.CONSOLE.layout.ConversionPattern=%d [%t] %-5p %c %x - %m%n
   
   # AUDIT is set to be a File appender using a PatternLayout.
   log4j.appender.AUDIT=org.apache.log4j.FileAppender
   log4j.appender.AUDIT.File=${catalina.base}/logs/audit.log
   log4j.appender.AUDIT.Append=true
   log4j.appender.AUDIT.Threshold=DEBUG
   log4j.appender.AUDIT.layout=org.apache.log4j.PatternLayout
   log4j.appender.AUDIT.layout.ConversionPattern=%m%n
   

The audit log file looks like this if configured as above:

5/10/13 8:59:59 AM;SUCCESS;2839ms;127.0.0.1;57378;Issue;https://localhost:9443/fediz-idp-sts/STSService;null;alice;null;null;http://docs.oasis-open.org/wss/oasis-wss-saml-token-profile-1.1#SAMLV2.0;https://localhost:8081/doubleit/services/doubleittransportsaml1claims;null;null;

Enjoy.