Turning on Security Logging

When authentication and authorization aren't behaving the way you'd like, the first step is turning on security-related debug output. This involves editing a Log4J configuration file.

Background Information

There are two general settings in log4j.xml that can affect logging:

  • Threshold: Each appender can have a Threshold param. "By setting the threshold value, only log messages matching the threshold setting or above will be logged."
    <appender ...>
      ...
      <param name="Threshold" value="..."/>
      ...
    </appender>
    
  • Root logger priority: "The most important logger you need to configure is the root logger. All loggers inherit their settings from the root logger."
    <root>
      <priority value="..." />
      ...
    </root>
    

Steps

  1. Make a backup copy of pentaho/WEB-INF/classes/log4j.xml.
  2. Open log4j.xml. Remove any Threshold param that occurs in all of the appenders (i.e. PENTAHOFILE or PENTAHOCONSOLE).
    log4j.xml
    <appender name="PENTAHOFILE" class="org.apache.log4j.DailyRollingFileAppender">
      <!-- THRESHOLD REMOVED -->
    </appender>
    
    <appender name="PENTAHOCONSOLE" class="org.apache.log4j.ConsoleAppender">
      <!-- THRESHOLD REMOVED -->
    </appender>
    
  3. Staying in the same file, find the root logger definition. Add or change the existing priority to WARN, ERROR, or FATAL. All loggers will inherit this level except where it is overridden (which is done in the next step).
    log4j.xml
    <root>
      <priority value="WARN" />
      <appender-ref ref="PENTAHOCONSOLE"/>
      <appender-ref ref="PENTAHOFILE"/>
    </root>
    
  4. Staying in the same file, add the following loggers before the root element. This will enable debug-level output in security-related classes.

    Note: When you add category elements, be sure to add them before the root element. Otherwise, you will violate the DTD for log4j.xml.

    log4j.xml
    <!-- all Spring Security classes will be set to DEBUG -->
    <category name="org.springframework.security">
      <priority value="DEBUG" />
    </category>
    
    <!-- all Pentaho security-related classes will be set to DEBUG -->
    <category name="org.pentaho.platform.engine.security">
      <priority value="DEBUG" />
    </category>
    <category name="org.pentaho.platform.plugin.services.security">
      <priority value="DEBUG" />
    </category>
    
  5. Now open pentaho-solutions/system/applicationContext-spring-security-<back-end>.xml where <back-end> is one of memory, jdbc, ldap, or hibernate. Which one you open will depend on the type of security back-end you've configured in web.xml. Add a property called hideUserNotFoundExceptions with value false to the bean with id daoAuthenticationProvider. Your modified bean should look like the bean below. Note that existing properties and constructor-args elements for this bean should be left unmodified.
    applicationContext-spring-security-<back-end>.xml
    <bean id="daoAuthenticationProvider" class="...">
      <!-- other properties/constructor-args not shown -->
      <property name="hideUserNotFoundExceptions" value="false" />
    </bean>
    
  6. Save the file and restart your servlet container or application server.

What to Look For

  • When you request a page that is protected but you are not yet logged in, you should see an exception in the log which looks like this:
    Log

    DEBUG [PentahoDoc:ExceptionTranslationFilter] Access is denied (user is anonymous); redirecting to authentication entry point org.springframework.security.AccessDeniedException: Access is denied

  • When the username and/or password doesn't match what's in the back-end, you should see a log message which looks like this:
    Log

    WARN [PentahoDoc:LoggerListener] Authentication event AuthenticationFailureBadCredentialsEvent: suzy; details: org.springframework.security.ui.WebAuthenticationDetails@fffd148a: RemoteIpAddress: 127.0.0.1; SessionId: 976C95033136070E0200D6DA26CB0277; exception: Bad credentials

  • When the username and password match, you should see a log message which looks like the following. After the InteractiveAuthenticationSuccessEvent, one of the filters will show the roles fetched for the authenticated user. Compare these roles to the page-role mapping found in the filterInvocationInterceptor bean in applicationContext-spring-security.xml.
    Log

    WARN [PentahoDoc:LoggerListener] Authentication event InteractiveAuthenticationSuccessEvent: suzy; details: org.springframework.security.ui.WebAuthenticationDetails@fffd148a: RemoteIpAddress: 127.0.0.1; SessionId: 976C95033136070E0200D6DA26CB0277
    DEBUG [PentahoDoc:HttpSessionContextIntegrationFilter] SecurityContext stored to HttpSession: 'org.springframework.security.context.SecurityContextImpl@2b86afeb: Authentication: org.springframework.security.providers.UsernamePasswordAuthenticationToken@2b86afeb: Username: org.springframework.security.userdetails.ldap.LdapUserDetailsImpl@d7f51e; Password: [PentahoDoc:PROTECTED]; Authenticated: true; Details: org.springframework.security.ui.WebAuthenticationDetails@fffd148a: RemoteIpAddress: 127.0.0.1; SessionId: 976C95033136070E0200D6DA26CB0277; Granted Authorities: ROLE_CTO, ROLE_IS, ROLE_AUTHENTICATED'

References

http://wiki.apache.org/logging-log4j/Log4jXmlFormat