5 Replies Latest reply on Mar 14, 2007 11:00 AM by real staple

    NotSerializableException in JBossCache with Log4J Level clas

    Martin Uhlig Newbie

      Hi,

      I'm wondering whether someone has had this problem before, because I couldn't find anything about it in the forums. From time to time in my logs I see this exception:

      2006-11-22 17:19:21,104 ERROR [org.jboss.web.tomcat.tc5.session.JBossCacheService] externalizeSession(): exception occurred externalizing session SessionBasedClusteredSession[id: POpO-xNbPcMuoMCfHsgI2w**.node01 lastAccessedTime: 1164212361095 version: 27 lastOutdated: 0]
      java.io.NotSerializableException: org.apache.log4j.Level
       at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1081)
       at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1375)
       at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1347)
       at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1290)
       at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1079)
       at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1375)
       at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1347)
       at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1290)
       at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1079)
       at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1375)
       at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1347)
       at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1290)
       at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1079)
       at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:302)
       at java.util.HashSet.writeObject(HashSet.java:254)
       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
       at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
       at java.lang.reflect.Method.invoke(Method.java:585)
       at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:917)
       at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1339)
       at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1290)
       at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1079)
       at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:302)
       at java.util.HashMap.writeObject(HashMap.java:1039)
       at sun.reflect.GeneratedMethodAccessor134.invoke(Unknown Source)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
       at java.lang.reflect.Method.invoke(Method.java:585)
       at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:917)
       at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1339)
       at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1290)
       at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1079)
       at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:302)
       at java.util.Hashtable.writeObject(Hashtable.java:813)
       at sun.reflect.GeneratedMethodAccessor342.invoke(Unknown Source)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
       at java.lang.reflect.Method.invoke(Method.java:585)
       at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:917)
       at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1339)
       at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1290)
       at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1079)
       at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:302)
       at org.jboss.web.tomcat.tc5.session.SessionBasedClusteredSession.writeExternal(SessionBasedClusteredSession.java:175)
       at org.jboss.web.tomcat.tc5.session.JBossCacheService.externalizeSession(JBossCacheService.java:902)
       at org.jboss.web.tomcat.tc5.session.JBossCacheService.putSession(JBossCacheService.java:348)
       at org.jboss.web.tomcat.tc5.session.JBossCacheClusteredSession.processSessionRepl(JBossCacheClusteredSession.java:122)
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.processSessionRepl(JBossCacheManager.java:994)
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.storeSession(JBossCacheManager.java:637)
       at org.jboss.web.tomcat.tc5.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:52)
       at org.jboss.web.tomcat.tc5.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:105)
       at org.jboss.web.tomcat.tc5.session.JvmRouteValve.invoke(JvmRouteValve.java:84)
       at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:432)
       at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74)
       at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
       at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
       at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
       at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
       at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:199)
       at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:282)
       at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:754)
       at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:684)
       at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:876)
       at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
       at java.lang.Thread.run(Thread.java:595)
      


      What I was able to find somewhere was a bug in Log4J saying the Level class is not serializable. Now I thought I would just replace the Log4J version that ships with JBoss 4.0.4 with a newer version (Log4J 1.2.13), but somehow the problem persists.

      What I replaced were the log4j.jar in server/all/lib, but not the log4j-boot.jar in the servers lib directory. I guess these are the classes that are still loaded first, and thus still causing the problem. But I am not sure on how to replace this log4j-boot.jar (if it's the source of the problem at all)? Could I just replace it with the normal log4j.jar?

      Thanks for your help and ideas
      Martin

        • 1. Re: NotSerializableException in JBossCache with Log4J Level
          Hany Mesha Novice

          You probably have an object in your application trying to store org.apache.log4j.Level instance in the session and that's why you're seeing the stack trace below.

          • 2. Re: NotSerializableException in JBossCache with Log4J Level
            Martin Uhlig Newbie

            I couldn't find a place where we would directly insert the Level class into the Session. Though this probably doesn't mean we don't do it indirectly somewhere.

            However, I replaced log4j-boot.jar in JBoss with my own version, and so far the problem has not shown again in the logs. Time will show whether this was the solution or not.

            Martin

            • 3. Re: NotSerializableException in JBossCache with Log4J Level
              Martin Gilday Newbie

              Did you find if this was the solution? I am getting the same problem but with Logger rather than Level. I have made a log4j-boot based on log4j 1.2.13 but I still get a doezen replication errors on every page load.

              Thanks.

              • 4. Re: NotSerializableException in JBossCache with Log4J Level
                Martin Uhlig Newbie

                I'm afraid the problem still exists. However, it was hidden for a while behind another serialization problem regarding java.lang.reflect.Method. Seems we/some of the frameworks we use are putting this into the Session. After searching for quite a long time I kind of gave up and just removed the exception from the log files by setting the log level to fatal. Not a very honorable thing to do, but I found that session replication and failover seems to work despite the problem, and that's what counts for me most.

                Regards
                Martin

                • 5. Re: NotSerializableException in JBossCache with Log4J Level
                  real staple Newbie

                  Any further word on this?

                  I created a listener that implements both HttpSessionAttributeListener and ServletContextAttributeListener (code below). It exposed a few other classes we were putting into the session.

                  However, I continue to get the log4j NonSerializable exceptions without any indication from the listener that something has been added that contains org.apache.log4j.Level.

                  import org.apache.commons.logging.Log;
                  import org.apache.commons.logging.LogFactory;

                  import javax.servlet.http.HttpSessionAttributeListener;
                  import javax.servlet.http.HttpSessionBindingEvent;
                  import javax.servlet.ServletContextAttributeListener;
                  import javax.servlet.ServletContextAttributeEvent;
                  import java.io.ObjectOutputStream;
                  import java.io.ByteArrayOutputStream;
                  import java.io.IOException;

                  public class FindNonSerializableSessionAttributesListener implements HttpSessionAttributeListener, ServletContextAttributeListener {
                  private static final Log logger = LogFactory.getLog(FindNonSerializableSessionAttributesListener.class);

                  public void attributeAdded(HttpSessionBindingEvent httpSessionBindingEvent) {
                  checkSerailizable(httpSessionBindingEvent.getName(), httpSessionBindingEvent.getValue());
                  }

                  public void attributeRemoved(HttpSessionBindingEvent httpSessionBindingEvent) {}

                  public void attributeReplaced(HttpSessionBindingEvent httpSessionBindingEvent) {
                  checkSerailizable(httpSessionBindingEvent.getName(), httpSessionBindingEvent.getValue());
                  }

                  private void checkSerailizable(String name, Object value) {
                  if (logger.isDebugEnabled()) {
                  try {
                  ObjectOutputStream out = new ObjectOutputStream(new ByteArrayOutputStream());
                  out.writeObject(value);
                  out.close();
                  out.flush();
                  } catch (IOException e) {
                  logger.info("Error serialiazing when setting session attribute " + name + "::" + value, e);
                  }
                  }
                  }

                  public void attributeAdded(ServletContextAttributeEvent servletContextAttributeEvent) {
                  checkSerailizable(servletContextAttributeEvent.getName(), servletContextAttributeEvent.getValue());
                  }

                  public void attributeRemoved(ServletContextAttributeEvent servletContextAttributeEvent) {
                  //To change body of implemented methods use File | Settings | File Templates.
                  }

                  public void attributeReplaced(ServletContextAttributeEvent servletContextAttributeEvent) {
                  checkSerailizable(servletContextAttributeEvent.getName(), servletContextAttributeEvent.getValue());
                  }
                  }