Kohei Nozaki's blog 

Recently I'm getting "javax.servlet.ServletException: Security Violation" 1 or 2 times per day from Roller (the blog engine this blog running on) and lost some unsaved paragraphs every time. I tried to back in such case, Safari and Firefox said the page has expired, and I couldn't take back my unsaved paragraphs. it's annoying so I started to find what the cause is.

Looking at stacktrace and I found that it comes from ValidateSaltFilter, and its related caching classes such as ExpiringLRUCacheFactoryImpl, but it's hard to reproduce, so I added some logging configuration and logging procedure to Roller to acquire more information.

Users can configure log4j which is logging framework Roller used at roller-custom.properties. I added following:

# Appender definition

log4j.appender.roller-debug=org.apache.log4j.DailyRollingFileAppender
log4j.appender.roller-debug.File=/Users/kyle/tmp/roller511/rollerdata/roller-debug.log
log4j.appender.roller-debug.layout=org.apache.log4j.PatternLayout
log4j.appender.roller-debug.layout.ConversionPattern=%-5p %d{yyyy-MM-dd HH:mm:ss,SSS} %C{1}:%M - %m%n
log4j.appender.roller-debug.Threshold=DEBUG

# Assign loggers to the appender which defined at the preceding.
# log4j.additivity means that stopping propagate to parent logger.

log4j.logger.org.apache.roller.weblogger.util.cache=DEBUG, roller-debug
log4j.additivity.org.apache.roller.weblogger.util.cache=false

log4j.logger.org.apache.roller.weblogger.ui.rendering.util.cache=DEBUG, roller-debug
log4j.additivity.org.apache.roller.weblogger.ui.rendering.util.cache=false

log4j.logger.org.apache.roller.weblogger.ui.core.filters.ValidateSaltFilter=DEBUG, roller-debug
log4j.additivity.org.apache.roller.weblogger.ui.core.filters.ValidateSaltFilter=false

     public void doFilter(ServletRequest request, ServletResponse response,
            FilterChain chain) throws IOException, ServletException {
        HttpServletRequest httpReq = (HttpServletRequest) request;

        // note enctype="multipart/form-data" does not send parameters (see
        // ROL-1956) requests of this type are stored in salt.ignored.urls in
        // roller.properties
        if (httpReq.getMethod().equals("POST")
                && !isIgnoredURL(httpReq.getServletPath())) {

            String salt = httpReq.getParameter("salt");
            SaltCache saltCache = SaltCache.getInstance();

            if (log.isDebugEnabled()) {

                try {
                    final Field contentCache = SaltCache.class.getDeclaredField("contentCache");
                    contentCache.setAccessible(true);
                    Object contentCacheValue = contentCache.get(saltCache);
                    
                    final Field cache = LRUCacheImpl.class.getDeclaredField("cache");
                    cache.setAccessible(true);
                    Object cacheValue = cache.get(contentCacheValue);
                    
                    Map cacheMap = (Map) cacheValue;
                    final Set set = cacheMap.keySet();
                    
                    log.debug("Salt which is just received: " + salt);
                    for (Object o : set) {
                        log.debug("Salt in the map: " + o);
                    }
                    
                } catch (NoSuchFieldException e) {
                    throw new RuntimeException(e);
                } catch (IllegalAccessException e) {
                    throw new RuntimeException(e);
                }

                if (salt == null) {
                    log.debug("salt == null");
                }
                else if (saltCache.get(salt) == null) {
                    log.debug("saltCache.get(salt) == null. salt=" + salt);
                }
                else if (saltCache.get(salt).equals(false)) {
                    log.debug("saltCache.get(salt).equals(false). salt=" + salt);
                }
            }

            if (salt == null || saltCache.get(salt) == null
                    || saltCache.get(salt).equals(false)) {

                if (log.isDebugEnabled()) {
                    log.debug("Salt value not found on POST to URL : "
                            + httpReq.getServletPath());
                }

                throw new ServletException("Security Violation");
            }
        }

        chain.doFilter(request, response);
    }

I added all of additional procedures inside if (log.isDebugEnabled()) so I won't need to remove these procedures after investigation. all I need will that just edit roller-custom.properties and reload Roller.

Now I can see how all of salts are creating, removing and be judged which was hit or miss from the log, so I'll take a look it when the problem occurred again.

UPDATE: I think I found the cause. see JIRA.

This post describes how to install Apache Derby 10.11.1.1 as Embedded Server to WildFly 8.2.0.Final. following instructions are intended to use with jboss-cli.

1. Install jars of Derby as a module into WildFly (assume jar files are located in /tmp)

   module add \
    --name=org.apache.derby \
    --resources=/tmp/derby.jar,/tmp/derbynet.jar,/tmp/derbytools.jar \
    --resource-delimiter=, \
    --dependencies=javax.api,javax.transaction.api
   

2. Register JDBC Driver named "derby-embedded"

   /subsystem=datasources/jdbc-driver=derby-embedded:add(driver-name=derby-embedded, \
    driver-module-name=org.apache.derby, \
    driver-class-name=org.apache.derby.jdbc.EmbeddedDriver, \
    driver-datasource-class-name=org.apache.derby.jdbc.EmbeddedDataSource, \
    driver-xa-datasource-class-name=org.apache.derby.jdbc.EmbeddedXADataSource)
   

3. Deploy a MBean which executes the shutdown procedure of Derby

   git clone https://github.com/lbtc-xxx/derby-shutdown-service
   cd derby-shutdown-service; mvn clean package
   cp target/derby-shutdown-service.jar $WILDFLY_HOME/standalone/deployments
   

4. Define a system property which triggers Derby to listen a port

   /system-property=derby.drda.startNetworkServer:add(value=true)

5. Define a system property to specify the port Derby will be listening

   /system-property=derby.drda.portNumber:add(value="1527")

6. Define a system property to specify where log file of Derby will be wrote

   /system-property=derby.stream.error.file:add(value="${jboss.server.log.dir}/derby.log")

7. Define a system property to append derby.log to exist one

   /system-property=derby.infolog.append:add(value="true")

8. (For Hibernate user) Add following dependency to modules/system/layers/base/org/hibernate/main/module.xml

   <module name="org.apache.derby"/>

   This prevents following warning:

   WARN  [org.hibernate.dialect.DerbyDialect] (ServerService Thread Pool -- 72) HHH000328: Unable to load/access derby driver class sysinfo to check versions : org.apache.derby.tools.sysinfo from [Module "org.hibernate:main" from local module loader @11028347 (finder: local module finder @14899482 (roots: /Users/kyle/servers/wildfly-8.2.0.Final/modules,/Users/kyle/servers/wildfly-8.2.0.Final/modules/system/layers/base))]

9. Define a DataSource

For Regular DataSource:

data-source add \
 --name=DerbyEmbeddedDS \
 --driver-name=derby-embedded \
 --connection-url=jdbc:derby:${jboss.server.base.dir}/derbydata;create=true \
 --jndi-name=java:jboss/jdbc/DerbyEmbeddedDS \
 --user-name=app \
 --password=app

For XA DataSource:

xa-data-source add \
 --name=DerbyEmbeddedXADS \
 --driver-name=derby-embedded \
 --jndi-name=java:jboss/jdbc/DerbyEmbeddedXADS \
 --user-name=app \
 --password=app \
 --same-rm-override=false \
 --xa-datasource-properties={ \
  "DatabaseName" => "${jboss.server.base.dir}/derbyxadata", \
  "CreateDatabase" => "create"}

10. Test connection

    /subsystem=datasources/data-source=DerbyEmbeddedDS:test-connection-in-pool

Also you need to ensure that shutdown script such as /etc/init.d/wildfly to not execute forcing termination (kill -9) unexpectedly. it will be triggered by exceed timeout of 30 seconds as default and it may bring database corruption in case that executing force shutdown during shutdown process of Derby. I think that longer timeout would be considerable for poor environment.

References

• Appendix C. Datasources (IronJacamar 1.1 User's Guide)
• How to shutdown embedded Derby which is defined as a DataSource properly on WildFly - Stack Overflow