Log4j 2
  1. Log4j 2
  2. LOG4J2-344

Log4j2 doesnt work with Weblogic 12c

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.0-beta8
    • Fix Version/s: 2.0-rc1
    • Component/s: None
    • Labels:
      None
    • Environment:

      Windows XP SP 3

      Description

      I get a "Context destroyed before it was initialized" exception, the problem seems to be that the servlet filters init method is not being called by WebLogic, not sure why...

        Issue Links

          Activity

          Hide
          Remko Popma added a comment -

          Could you post a full stack trace, your log4j config, and which log4j jars your have in your classpath?

          Show
          Remko Popma added a comment - Could you post a full stack trace, your log4j config, and which log4j jars your have in your classpath?
          Hide
          Remko Popma added a comment -

          Keir, do you have any additional information? This does not give us much to go on...

          Show
          Remko Popma added a comment - Keir, do you have any additional information? This does not give us much to go on...
          Hide
          Keir added a comment -

          Sorry, been away, will post up later today

          Show
          Keir added a comment - Sorry, been away, will post up later today
          Hide
          Keir added a comment -

          <16-Aug-2013 16:42:48 o'clock BST> <Error> <HTTP> <BEA-101020> <[ServletContext@21622502[app:_auto_generated_ear_ module:myapp path:null spec-version:3.0]] Servlet failed with an Exception
          java.lang.NullPointerException
          at org.apache.logging.log4j.core.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:68)
          at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:74)
          at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3288)
          at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3254)
          at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
          Truncated. see log file for complete stacktrace

          Show
          Keir added a comment - <16-Aug-2013 16:42:48 o'clock BST> <Error> <HTTP> <BEA-101020> <[ServletContext@21622502 [app:_auto_generated_ear_ module:myapp path:null spec-version:3.0] ] Servlet failed with an Exception java.lang.NullPointerException at org.apache.logging.log4j.core.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:68) at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:74) at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3288) at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3254) at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321) Truncated. see log file for complete stacktrace
          Hide
          Keir added a comment -

          <dependency>
          <groupId>org.apache.logging.log4j</groupId>
          <artifactId>log4j-api</artifactId>
          <version>2.0-beta8</version>
          </dependency>
          <dependency>
          <groupId>org.apache.logging.log4j</groupId>
          <artifactId>log4j-core</artifactId>
          <version>2.0-beta8</version>
          </dependency>
          <dependency>
          <groupId>org.apache.logging.log4j</groupId>
          <artifactId>log4j-slf4j-impl</artifactId>
          <version>2.0-beta8</version>
          </dependency>

          Show
          Keir added a comment - <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-api</artifactId> <version>2.0-beta8</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>2.0-beta8</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-slf4j-impl</artifactId> <version>2.0-beta8</version> </dependency>
          Hide
          Keir added a comment -

          <?xml version="1.0" encoding="UTF-8"?>
          <configuration>
          <appenders>
          <Console name="Console" target="SYSTEM_OUT">
          <PatternLayout pattern="[%d

          {HH:mm:ss}

          %-5level]%msg (%logger

          {3.}

          )%n"/>
          </Console>
          </appenders>

          <loggers>

          <!-- Application Loggers -->
          <logger name="com.myapp" level="info"/>

          <!-- 3rdparty Loggers -->
          <logger name="org.springframework.core" level="warn"/>
          <logger name="org.springframework.beans" level="warn"/>
          <logger name="org.springframework.context" level="warn"/>
          <logger name="org.springframework.web" level="warn"/>
          <logger name="org.springframework.security" level="warn"/>

          <!-- Root Logger -->
          <root level="info">
          <appender-ref ref="Console" />
          </root>

          </loggers>

          </configuration>

          Show
          Keir added a comment - <?xml version="1.0" encoding="UTF-8"?> <configuration> <appenders> <Console name="Console" target="SYSTEM_OUT"> <PatternLayout pattern="[%d {HH:mm:ss} %-5level]%msg (%logger {3.} )%n"/> </Console> </appenders> <loggers> <!-- Application Loggers --> <logger name="com.myapp" level="info"/> <!-- 3rdparty Loggers --> <logger name="org.springframework.core" level="warn"/> <logger name="org.springframework.beans" level="warn"/> <logger name="org.springframework.context" level="warn"/> <logger name="org.springframework.web" level="warn"/> <logger name="org.springframework.security" level="warn"/> <!-- Root Logger --> <root level="info"> <appender-ref ref="Console" /> </root> </loggers> </configuration>
          Hide
          Gary Gregory added a comment - - edited

          Hm... it looks like the initializer is null. We must have one of:

          1. The thread that assigned the filter's initializer is different from the thread calling doFilter() and the change to initializer is not visible to the doFilter() thread, making the initializer volatile may be required.
          2. A race condition whereby the filter's init method is not done before doFilter is called from a different thread.
          Show
          Gary Gregory added a comment - - edited Hm... it looks like the initializer is null. We must have one of: The thread that assigned the filter's initializer is different from the thread calling doFilter() and the change to initializer is not visible to the doFilter() thread, making the initializer volatile may be required. A race condition whereby the filter's init method is not done before doFilter is called from a different thread.
          Hide
          Ralph Goers added a comment - - edited

          The javadoc for init says - "The init method must complete successfully before the filter is asked to do any filtering work.". Neither of your two possibilities are allowed with this required behavior.

          Actually, I guess I could see how the first bullet could happen except every servlet filter example you will find doesn't do that.

          Show
          Ralph Goers added a comment - - edited The javadoc for init says - "The init method must complete successfully before the filter is asked to do any filtering work.". Neither of your two possibilities are allowed with this required behavior. Actually, I guess I could see how the first bullet could happen except every servlet filter example you will find doesn't do that.
          Hide
          Gary Gregory added a comment -

          And yet there is the NPE

          Show
          Gary Gregory added a comment - And yet there is the NPE
          Hide
          Nick Williams added a comment -

          The stack trace in question can ONLY happen if WebLogic is in violation of the spec. WebLogic is either calling doFilter before it calls init or calling doFilter after it calls destroy, both of which are illegal behaviors. You need to contact WebLogic support for assistance.

          Show
          Nick Williams added a comment - The stack trace in question can ONLY happen if WebLogic is in violation of the spec. WebLogic is either calling doFilter before it calls init or calling doFilter after it calls destroy , both of which are illegal behaviors. You need to contact WebLogic support for assistance.
          Hide
          Gary Gregory added a comment -

          Should we bullet-proof our filter such that it logs errors instead of throwing NPEs?

          Show
          Gary Gregory added a comment - Should we bullet-proof our filter such that it logs errors instead of throwing NPEs?
          Hide
          Nick Williams added a comment - - edited

          I thought about it, but doing so makes me nervous. This would mask implementation problems in the container. If thousands of Log4j users complain to WebLogic because their applications won't work, such a bug is going to get fixed really quickly...

          I think we should probably contact Oracle and report the problem and see whether we think they'll act on it in a reasonable timeframe before we make such a move.

          Important
          I suppose it's possible there's something wrong with org.apache.logging.log4j.core.web.Log4jWebInitializerImpl#getLog4jWebInitializer(ServletContext), such that it can return a null value, but:

          1. Reading the code again, I can't for the life of me understand how it could possibly return null; and,
          2. If it did return null, we should also be seeing an NPE from line 52 in init.
          Show
          Nick Williams added a comment - - edited I thought about it, but doing so makes me nervous. This would mask implementation problems in the container. If thousands of Log4j users complain to WebLogic because their applications won't work, such a bug is going to get fixed really quickly... I think we should probably contact Oracle and report the problem and see whether we think they'll act on it in a reasonable timeframe before we make such a move. Important I suppose it's possible there's something wrong with org.apache.logging.log4j.core.web.Log4jWebInitializerImpl#getLog4jWebInitializer(ServletContext) , such that it can return a null value, but: Reading the code again, I can't for the life of me understand how it could possibly return null ; and, If it did return null , we should also be seeing an NPE from line 52 in init .
          Hide
          Remko Popma added a comment -

          Keir,

          Your stacktrace says "Truncated. see log file for complete stacktrace".
          Can you attach the full stack trace from the log?
          It may be possible to answer the questions raised above when we have more information...

          Show
          Remko Popma added a comment - Keir, Your stacktrace says "Truncated. see log file for complete stacktrace". Can you attach the full stack trace from the log? It may be possible to answer the questions raised above when we have more information...
          Hide
          Nick Williams added a comment -

          Keir, just for kicks, can you also post your web.xml configuration? It's possible this is related to LOG4J2-359.

          Show
          Nick Williams added a comment - Keir, just for kicks, can you also post your web.xml configuration? It's possible this is related to LOG4J2-359 .
          Hide
          Remko Popma added a comment -

          Keir, it would also be good to know if your log contains the string "Log4jServletFilter initialized." before the error occurred.

          Show
          Remko Popma added a comment - Keir, it would also be good to know if your log contains the string "Log4jServletFilter initialized." before the error occurred.
          Hide
          Keir added a comment -

          Don't see "Log4jServletFilter initialized." though my log level is set to info so if its a debug message then I wouldn't. Not sure where to find the log file, I have only specified a console appender? Will attach web.xml.

          Show
          Keir added a comment - Don't see "Log4jServletFilter initialized." though my log level is set to info so if its a debug message then I wouldn't. Not sure where to find the log file, I have only specified a console appender? Will attach web.xml.
          Hide
          Tomasz Wladzinski added a comment - - edited

          I had the same issue. My investigation showed that when you add servlet filter using ServletContext.addFilter(java.lang.String filterName, Filter filter) WebLogic does not invoke filter's init method. Most probably assuming that you were to do it as you created the instance. When I changed it to addFilter(java.lang.String filterName, java.lang.String className) everything worked in order.

          Show
          Tomasz Wladzinski added a comment - - edited I had the same issue. My investigation showed that when you add servlet filter using ServletContext.addFilter(java.lang.String filterName, Filter filter) WebLogic does not invoke filter's init method. Most probably assuming that you were to do it as you created the instance. When I changed it to addFilter(java.lang.String filterName, java.lang.String className) everything worked in order.
          Hide
          Nick Williams added a comment -

          Thanks for discovering this, Tomasz! I don't have access to a WebLogic environment, so it's hard for me to troubleshoot. I suspect that WebLogic's behavior here is a violation of the spec (reasoning: it would be invalid to initialize the filter at the time you call addFilter, because the filter is supposed to be initialized at a later phase of the application lifecycle). However, now it looks like we have a non-hacky approach to solving this problem.

          Can you try out one thing for me? I'm wondering if using addFilter(String filterName, Class<? extends Filter> filterClass) works as well. This would be preferable, as it would be more compile safe. Let me know whether that works, and then I'll make the change.

          Show
          Nick Williams added a comment - Thanks for discovering this, Tomasz! I don't have access to a WebLogic environment, so it's hard for me to troubleshoot. I suspect that WebLogic's behavior here is a violation of the spec (reasoning: it would be invalid to initialize the filter at the time you call addFilter , because the filter is supposed to be initialized at a later phase of the application lifecycle). However, now it looks like we have a non-hacky approach to solving this problem. Can you try out one thing for me? I'm wondering if using addFilter(String filterName, Class<? extends Filter> filterClass) works as well. This would be preferable, as it would be more compile safe. Let me know whether that works, and then I'll make the change.
          Hide
          Tomasz Wladzinski added a comment -

          I switched addFilter to the one with Class parameter and it worked well so if this solution works with other containers you got the solution . For test purposes I used 2.0-beta9 code and WebLogic 12.1.1.0.

          My guess was not thoroughly thought through. It seems that there is a bug in WebLogic. I tried to find any information on the internet but without success.

          Show
          Tomasz Wladzinski added a comment - I switched addFilter to the one with Class parameter and it worked well so if this solution works with other containers you got the solution . For test purposes I used 2.0-beta9 code and WebLogic 12.1.1.0. My guess was not thoroughly thought through. It seems that there is a bug in WebLogic. I tried to find any information on the internet but without success.
          Hide
          Russell Codlin added a comment -

          Just confirming I've seen the same issue on WebLogic 12c and the changes recommended above were successful. The change has also been successfully tested on Glassfish (3.1 and 4.0) and Tomcat 7.0.42. We've also tested on Weblogic 10.3.6 but this is a 2.5 Servlet container so different configuration approach.

          Show
          Russell Codlin added a comment - Just confirming I've seen the same issue on WebLogic 12c and the changes recommended above were successful. The change has also been successfully tested on Glassfish (3.1 and 4.0) and Tomcat 7.0.42. We've also tested on Weblogic 10.3.6 but this is a 2.5 Servlet container so different configuration approach.
          Hide
          Sergio Enrique Garcia Lopez added a comment -

          In which class is the method addFilter that you commmented?

          Show
          Sergio Enrique Garcia Lopez added a comment - In which class is the method addFilter that you commmented?
          Hide
          Russell Codlin added a comment -

          Change is carried out in org.apache.logging.log4j.core.web.Log4jServletContainerInitializer

          Show
          Russell Codlin added a comment - Change is carried out in org.apache.logging.log4j.core.web.Log4jServletContainerInitializer
          Hide
          Matt Sicker added a comment -

          These seem like similar bugs.

          Show
          Matt Sicker added a comment - These seem like similar bugs.
          Hide
          Marco Antonelli added a comment -

          Hi there, any news on this issue?

          Show
          Marco Antonelli added a comment - Hi there, any news on this issue?
          Hide
          Nick Williams added a comment -

          Sorry for the delay. This has been fixed with r1561937.

          Show
          Nick Williams added a comment - Sorry for the delay. This has been fixed with r1561937.

            People

            • Assignee:
              Nick Williams
              Reporter:
              Keir
            • Votes:
              0 Vote for this issue
              Watchers:
              11 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development