Wednesday, February 27, 2008

Track non-serializable objects in Click Framework

Click 1.4 provides support for stateful pages by adding the page as an attribute to the HttpSession.

Now I guess your saying, “But what if my page is not serializable?“.

Obviously if your page or any reference on the page is not serializable you will receive a NotSerializableException.

java.io.NotSerializableException: za.co.abc.presentation.control.Three
at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1153)
at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1509)
at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1474)
at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1392)
The problem with NotSerializableException is that it does not always provide you with the information you need to track down the object. Sure it might tell you which object is problematic, but not how to track it.

JDK6 provides a nice solution for this. Start the JVM with the option -Dsun.io.serialization.extendedDebugInfo=true and the stackTrace will look like this:
java.io.NotSerializableException: za.co.abc.presentation.control.Three
- field (class "za.co.abc.presentation.control.Two", name: "three", type: "class za.co.abc.presentation.control.Three")
- object (class "za.co.abc.presentation.control.Two", za.co.abc.presentation.control.Two@fbbb20)
- field (class "za.co.abc.presentation.control.One", name: "two", type: "class za.co.abc.presentation.control.Two")
- object (class "za.co.abc.presentation.control.One", za.co.abc.presentation.control.One@17ee6c9)
- field (class "za.co.abc.presentation.control.Trail", name: "one", type: "class za.co.abc.presentation.control.One")
- root object (class "za.co.abc.presentation.control.Trail", {/click-tests/home.htm=home})
at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1153)
at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1509)
at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1474)
at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1392)
Reading the strackTrace from the bottom up one can see that the root object Trail references an object of type One which references an object of type Two which references an object of type Three which is not-serializable.

All good and well for JDK6 users, but what if you're still on JDK 1.4?

Bob Lee has provided a similar solution for tracking serialization errors and this will work in JVM's prior to JDK6.

Let's look at how we can apply his solution to detect and trace serialization errors when storing objects as attributes in the HttpSession.

We do this by implementing HttpSessionAttributeListener and whenever an attribute is added or replaced we serialize the new value and log out any errors.

Here is the output from the listener:
[Click] [error] Attribute => {trail, class za.co.abc.presentation.control.Trail} is not serializable.
Path to bad object:
- za.co.abc.presentation.control.Trail@c38d79cb,
- za.co.abc.presentation.control.One@1a505be,
- za.co.abc.presentation.control.Two@9740de,
- za.co.abc.presentation.control.Three@f3d0fc
Very similar to the JDK6 output but now read the output from top to bottom. Trail references an object of type One which in turn references an object of type Two which references an object of type Three which is not-serializable.

To use this in your own Click project simply copy the class below into your project and add the following snippet to your web.xml:
<listener>
<listener-class>yourpackage.AttributeSerializationDebugger</listener-class>
</listener>
Java class:
package yourpackage;

import java.io.ByteArrayOutputStream;
import java.io.ObjectOutputStream;
import java.io.OutputStream;
import java.io.IOException;
import java.lang.reflect.Field;
import java.util.List;
import java.util.ArrayList;
import java.util.Iterator;
import javax.servlet.http.HttpSessionAttributeListener;
import javax.servlet.http.HttpSessionBindingEvent;
import net.sf.click.Control;
import net.sf.click.util.ClickLogger;
import net.sf.click.util.ClickUtils;
import net.sf.click.util.HtmlStringBuffer;

/**
* Adapted from the article: http://crazybob.org/2007/02/debugging-serialization.html
*
*

* <listener>
* <listener-class>yourpackage.AttributeSerializationDebugger</listener-class>
* </listener>
*

*
* You can get the same functionality from Sun JDK6 when specifying the JVM options: -Dsun.io.serialization.extendedDebugInfo=true
*/
public class AttributeSerializationDebugger implements HttpSessionAttributeListener {

public void attributeAdded(HttpSessionBindingEvent event) {
testSerialization(event.getName(), event.getValue());
}

public void attributeRemoved(HttpSessionBindingEvent event) {
}

public void attributeReplaced(HttpSessionBindingEvent event) {
testSerialization(event.getName(), event.getValue());
}

public void testSerialization(String name, Object value) {
DebuggingObjectOutputStream out = null;
try {
out = new DebuggingObjectOutputStream(new ByteArrayOutputStream());
out.writeObject(value);
} catch (Exception e) {
HtmlStringBuffer msg = new HtmlStringBuffer();
msg.append("Attribute => {");
msg.append(name);
msg.append(", ");
msg.append(value.getClass());
msg.append("} is not serializable.\n\tPath to bad object:");
msg.append(out.getStack());
msg.append("\n\n\tException message: ");
msg.append(e.getMessage());
ClickLogger.getInstance().error(msg);
} finally {
ClickUtils.close(out);
}
}

static class DebuggingObjectOutputStream extends ObjectOutputStream {

private static final Field DEPTH_FIELD;

static {
try {
DEPTH_FIELD = ObjectOutputStream.class.getDeclaredField("depth");
DEPTH_FIELD.setAccessible(true);
} catch (NoSuchFieldException e) {
throw new AssertionError(e);
}
}

final List stack = new ArrayList() {

public String toString() {
HtmlStringBuffer buf = new HtmlStringBuffer();
Iterator i = iterator();

boolean hasNext = i.hasNext();

while (hasNext) {
Object o = i.next();
buf.append("\n\t- ");
buf.append(o == this ? "(this Collection)" : String.valueOf(o));
hasNext = i.hasNext();
if (hasNext) {
buf.append(", ");
}
}

return buf.toString();
}
};

/**
* Indicates whether or not OOS has tried to
* write an IOException (presumably as the
* result of a serialization error) to the
* stream.
*/
boolean broken = false;

public DebuggingObjectOutputStream(
OutputStream out) throws IOException {
super(out);
enableReplaceObject(true);
}

/**
* Abuse {@code replaceObject()} as a hook to
* maintain our stack.
*/
protected Object replaceObject(Object o) {
// ObjectOutputStream writes serialization
// exceptions to the stream. Ignore
// everything after that so we don't lose
// the path to a non-serializable object. So
// long as the user doesn't write an
// IOException as the root object, we're OK.
int currentDepth = currentDepth();
if (o instanceof IOException && currentDepth == 0) {
broken = true;
}
if (!broken) {
truncate(currentDepth);
stack.add(toString(o));
}
return o;
}

protected String toString(Object o) {
HtmlStringBuffer buffer = new HtmlStringBuffer(30);
buffer.append(o.getClass().getName() + "@" + Integer.toHexString(o.hashCode()));
if (o instanceof Control) {
Control c = (Control) o;
buffer.append(" controlName : " + c.getName());
}
return buffer.toString();
}

private void truncate(int depth) {
while (stack.size() > depth) {
pop();
}
}

private Object pop() {
return stack.remove(stack.size() - 1);
}

/**
* Returns a 0-based depth within the object
* graph of the current object being
* serialized.
*/
private int currentDepth() {
try {
Integer oneBased = ((Integer) DEPTH_FIELD.get(this));
return oneBased.intValue() - 1;
} catch (IllegalAccessException e) {
throw new AssertionError(e);
}
}

/**
* Returns the path to the last object
* serialized. If an exception occurred, this
* should be the path to the non-serializable
* object.
*/
public List getStack() {
return stack;
}
}
}

2 comments:

Anonymous said...

Hi Bob, Your post helped me to solve an issue with serialization that I faced while calling a remote EJB on JBOSS. Apparently the object returned by the EJB had a instance of Object class (non-serializable) deeply embedded in the object graph and it was becoming difficult to locate it with JDK 5. So I used JDK 6 with the flag and it identified the bug.
Thanks again.

Bob Schellink said...

Hi, glad it helped. Although all credit should go to Bob Lee :)