Uploaded image for project: 'Jira Data Center'
  1. Jira Data Center
  2. JRASERVER-12540

Velocity causing NullPointer Exception due to velocity.log not being writable when webwork inits its velocity helper.

XMLWordPrintable

      Click on Administration --> Click Project --> Select a Project ---> Project Role: View Members --> Edit a Role.

      This is when there is a null pointer exception, I will attach the screen in later comments.
      It seems that the application is trying to write to root /velocity.log file, which is not the case.

      Someone in support gave me a classpath.jsp to find out which velocity.properties was being used. This was of no help since I think it produced wrong output, and also provides misleading information about the actual velocity.properties being used.

      We have tried everything from moving around velocity.properties to put in explicitly in classpath. Nothing works. This is a bug

      Below is the stack trace
      ---------------------------------
      PANIC : Error configuring AvalonLogSystem : java.io.FileNotFoundException: /velocity.log (Permission denied)
      PANIC : Error configuring AvalonLogSystem : java.io.FileNotFoundException: /velocity.log (Permission denied)
      2007-04-11 10:41:22,188 [ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)' ERROR [webwork.view.velocity.VelocityHelper] Unable to configure AvalonLogSystem : java.io.FileNotFoundException: /velocity.log (Permission denied)
      java.lang.Exception: Unable to configure AvalonLogSystem : java.io.FileNotFoundException: /velocity.log (Permission denied)
      at org.apache.velocity.runtime.log.AvalonLogSystem.init(AvalonLogSystem.java:92)
      at org.apache.velocity.runtime.log.LogManager.createLogSystem(LogManager.java:127)
      at org.apache.velocity.runtime.RuntimeInstance.initializeLogger(RuntimeInstance.java:553)
      at org.apache.velocity.runtime.RuntimeInstance.init(RuntimeInstance.java:226)
      at org.apache.velocity.runtime.RuntimeInstance.init(RuntimeInstance.java:461)
      at org.apache.velocity.runtime.RuntimeSingleton.init(RuntimeSingleton.java:208)
      at org.apache.velocity.app.Velocity.init(Velocity.java:106)
      at webwork.view.velocity.VelocityHelper.initVelocity(VelocityHelper.java:128)
      at webwork.view.velocity.VelocityHelper.getContext(VelocityHelper.java:159)
      at com.atlassian.jira.plugin.webwork.JiraPluginWebworkVelocityServlet.service(JiraPluginWebworkVelocityServlet.java:43)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
      at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:223)
      at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
      at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:283)
      at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:26)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.web.filters.AccessLogFilter.doFilter(AccessLogFilter.java:51)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.seraph.filter.SecurityFilter.doFilter(SecurityFilter.java:83)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.seraph.filter.LoginFilter.doFilter(LoginFilter.java:92)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.web.filters.ActionCleanupDelayFilter.doFilter(ActionCleanupDelayFilter.java:31)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.web.filters.RequestCleanupFilter.doFilter(RequestCleanupFilter.java:31)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.core.filters.AbstractEncodingFilter.doFilter(AbstractEncodingFilter.java:37)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.appconsistency.db.DatabaseCompatibilityEnforcerFilter.doFilter(DatabaseCompatibilityEnforcerFilter.java:39)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at weblogic.servlet.internal.RequestDispatcherImpl.invokeServlet(RequestDispatcherImpl.java:501)
      at weblogic.servlet.internal.RequestDispatcherImpl.forward(RequestDispatcherImpl.java:245)
      2007-04-11 10:41:22,188 [ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)' ERROR [com.atlassian.velocity.DefaultVelocityManager] Exception getting message body from Velocity: java.lang.NullPointerException
      java.lang.NullPointerException
      at org.apache.velocity.context.InternalContextAdapterImpl.get(InternalContextAdapterImpl.java:162)
      at org.apache.velocity.runtime.parser.node.ASTReference.getVariableValue(ASTReference.java:623)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:151)
      at org.apache.velocity.runtime.parser.node.ASTReference.evaluate(ASTReference.java:307)
      at org.apache.velocity.runtime.parser.node.ASTExpression.evaluate(ASTExpression.java:45)
      at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:68)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:230)
      at org.apache.velocity.Template.merge(Template.java:256)
      at org.apache.velocity.app.VelocityEngine.mergeTemplate(VelocityEngine.java:450)
      at com.atlassian.velocity.DefaultVelocityManager.getEncodedBody(DefaultVelocityManager.java:76)
      at com.atlassian.jira.plugin.webwork.JiraPluginWebworkVelocityServlet.service(JiraPluginWebworkVelocityServlet.java:48)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
      at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:223)
      at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
      at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:283)
      at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:26)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.web.filters.AccessLogFilter.doFilter(AccessLogFilter.java:51)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.seraph.filter.SecurityFilter.doFilter(SecurityFilter.java:83)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.seraph.filter.LoginFilter.doFilter(LoginFilter.java:92)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.web.filters.ActionCleanupDelayFilter.doFilter(ActionCleanupDelayFilter.java:31)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.web.filters.RequestCleanupFilter.doFilter(RequestCleanupFilter.java:31)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.core.filters.AbstractEncodingFilter.doFilter(AbstractEncodingFilter.java:37)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at com.atlassian.jira.appconsistency.db.DatabaseCompatibilityEnforcerFilter.doFilter(DatabaseCompatibilityEnforcerFilter.java:39)
      at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
      at weblogic.servlet.internal.RequestDispatcherImpl.invokeServlet(RequestDispatcherImpl.java:501)

        1. Bug-screenshot.jpg
          Bug-screenshot.jpg
          322 kB

            [JRASERVER-12540] Velocity causing NullPointer Exception due to velocity.log not being writable when webwork inits its velocity helper.

            Jed Wesley-Smith (Inactive) added a comment - - edited

            The full fix is to stop WebWork initialising Velocity - JIRA already manages the velocity lifecycle. This required a patch to Velocity that is attached to WW-1454.

            Please note that the full fix is only in 3.9

            Jed Wesley-Smith (Inactive) added a comment - - edited The full fix is to stop WebWork initialising Velocity - JIRA already manages the velocity lifecycle. This required a patch to Velocity that is attached to WW-1454 . Please note that the full fix is only in 3.9

            Jed Wesley-Smith (Inactive) added a comment -

            fix checked in.

            Jed Wesley-Smith (Inactive) added a comment - fix checked in.

            Jed Wesley-Smith (Inactive) added a comment -

            When webwork inits velocity, it isn't bootstrapped with JIRA's velocity.properties, but with this properties file - which overrides the default velocity.properties in the velocity jar. When the log system is initialised, the default logsystem is the Avalon (commons-logging) logsystem.

            Mostly this causes a separate velocity.log to be created in the context directory, which doesn't normally cause problems, but can if for some reason that directory is write-protected. In that situation the default Avalon logsystem fails catastrophically (the first exception above), and webwork is not initialised returning a null Context to JIRA, and eventually dying with spurious NPEs. (the second exception).

            Jed Wesley-Smith (Inactive) added a comment - When webwork inits velocity, it isn't bootstrapped with JIRA's velocity.properties, but with this properties file - which overrides the default velocity.properties in the velocity jar. When the log system is initialised, the default logsystem is the Avalon (commons-logging) logsystem. Mostly this causes a separate velocity.log to be created in the context directory, which doesn't normally cause problems, but can if for some reason that directory is write-protected. In that situation the default Avalon logsystem fails catastrophically (the first exception above), and webwork is not initialised returning a null Context to JIRA, and eventually dying with spurious NPEs. (the second exception).

            Jed Wesley-Smith (Inactive) added a comment - - edited

            What happens is that when webwork initialises velocity, it doesn't use JIRA's velocity.properties, it uses the webwork Configuration. If velocity doesn't find required properties in the webwork Configuration, it falls back to the default velocity.properties in the velocity-1.4.jar rather than JIRA's WEB-INF/classes/velocity.properties.

            The solution is to copy velocity's relevant logsystem properties from velocity.properties to webwork.properties

            So add the following:

            runtime.log.logsystem.class = org.apache.velocity.runtime.log.SimpleLog4JLogSystem
runtime.log.logsystem.log4j.category=velocity

            to JIRA's WEB-INF/classes/webwork.properties

            Jed Wesley-Smith (Inactive) added a comment - - edited What happens is that when webwork initialises velocity, it doesn't use JIRA's velocity.properties, it uses the webwork Configuration. If velocity doesn't find required properties in the webwork Configuration, it falls back to the default velocity.properties in the velocity-1.4.jar rather than JIRA's WEB-INF/classes/velocity.properties . The solution is to copy velocity's relevant logsystem properties from velocity.properties to webwork.properties So add the following: runtime.log.logsystem.class = org.apache.velocity.runtime.log.SimpleLog4JLogSystem runtime.log.logsystem.log4j.category=velocity to JIRA's WEB-INF/classes/webwork.properties

            Saurabh Gupta added a comment -

            Please see what happens when you edit the project roles.

            Saurabh Gupta added a comment - Please see what happens when you edit the project roles.

              Unassigned Unassigned
              f03d2ebe4510 Saurabh Gupta
              Affected customers:
              0 This affects my team
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: