May 21, 2013

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:

BindingContext objcectSpring EventDocumentation
IssueTokenProviderParametersSTSIssueSuccessEvent
STSIssueFailureEvent
blog
ValidateTokenValidatorParametersSTSValidateSuccessEvent
STSValidateFailureEvent
blog
CancelTokenCancellerParametersSTSCancelSuccessEvent
STSCancelFailureEvent
blog
RenewTokenRenewerParametersSTSRenewSuccessEvent
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:

NameTypeMandatoryDefaultDescription
logFieldnameBooleanNoNoShould the fieldname be logged, ex. OPERATION=issue
dateFormatStringNogetDateTimeInstance(DateFormat.SHORT, DateFormat.MEDIUM)Format of the date
logLevelStringNoFINEWhich log level should be used?
logStacktraceBooleanNoNoIn case of an error, shall the stacktrace be logged?
fieldOrderList<String>NoTIME
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.

No comments:

Post a Comment