ObjectSave causes java.io.UTFDataFormatException

Question

Raised as bug with Railo https://issues.jboss.org/browse/RAILO-2698 - this question should be closed

I am currently attempting to ObjectSave() on a rather complex Struct which contains instances of some CFCs among other data using the following cfscript (this is a test script I put together to reproduce the issue)

<cfscript>
    thisState = session.objBasket.getState();
    writedump(thisState); // dumps the object successfully
    ObjectSave(thisState); // causes java.io.UTFDataFormatException
</cfscript>

I am getting the following error java.io.UTFDataFormatException (stack trace follows). Does anyone know of a way to fix this, or is it a matter of simply trying to use the wrong tool for the job?

Railo versions the error occurs on

• Railo 4.1.1.009 final (Java 1.7.0_45)
• Railo 4.1.1.009 final (Java 1.7.0_17)
• Railo 4.1.2.001 final (Java 1.7.0_45) (Preview release)

Railo versions the error does not occur on

• Railo 4.0.4.001 final (Java 1.7.0_45)

Stack trace of the error

java.io.UTFDataFormatException at java.io.ObjectOutputStream$BlockDataOutputStream.writeUTF(ObjectOutputStream.java:2163):2163 at java.io.ObjectOutputStream$BlockDataOutputStream.writeUTF(ObjectOutputStream.java:2006):2006 at java.io.ObjectOutputStream.writeUTF(ObjectOutputStream.java:868):868 at railo.runtime.ComponentImpl.writeExternal(ComponentImpl.java:1975):1975 at java.io.ObjectOutputStream.writeExternalData(ObjectOutputStream.java:1458):1458 at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1429):1429 at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177):1177 at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347):347 at java.util.HashMap.writeObject(HashMap.java:1133):1133 at sun.reflect.GeneratedMethodAccessor62.invoke(Unknown Source):-1 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43):43 at java.lang.reflect.Method.invoke(Method.java:606):606 at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:988):988 at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1495):1495 at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431):1431 at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177):1177 at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347):347 at railo.commons.collection.AbstractMapPro.writeExternal(AbstractMapPro.java:49):49 at java.io.ObjectOutputStream.writeExternalData(ObjectOutputStream.java:1458):1458 at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1429):1429 at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177):1177 at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1547):1547 at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1508):1508 at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431):1431 at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177):1177 at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347):347 at java.util.HashMap.writeObject(HashMap.java:1133):1133 at sun.reflect.GeneratedMethodAccessor62.invoke(Unknown Source):-1 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43):43 at java.lang.reflect.Method.invoke(Method.java:606):606 at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:988):988 at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1495):1495 at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431):1431 at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177):1177 at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347):347 at railo.commons.collection.AbstractMapPro.writeExternal(AbstractMapPro.java:49):49 at java.io.ObjectOutputStream.writeExternalData(ObjectOutputStream.java:1458):1458 at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1429):1429 at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177):1177 at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1547):1547 at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1508):1508 at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431):1431 at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177):1177 at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347):347 at railo.runtime.converter.JavaConverter.serialize(JavaConverter.java:67):67 at railo.runtime.functions.other.ObjectSave.call(ObjectSave.java:31):31 at railo.runtime.functions.other.ObjectSave.call(ObjectSave.java:22):22 at mso.clientobject_cfc$cf._3(/var/www/html/www/www.simon.test/mso/ClientObject.cfc:476):476 at mso.clientobject_cfc$cf.udfCall(/var/www/html/www/www.simon.test/mso/ClientObject.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:94):94 at railo.runtime.type.UDFImpl._call(UDFImpl.java:307):307 at railo.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:198):198 at railo.runtime.type.scope.UndefinedImpl.callWithNamedValues(UndefinedImpl.java:709):709 at railo.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:738):738 at railo.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1513):1513 at mso.clientobject_cfc$cf._3(/var/www/html/www/www.simon.test/mso/ClientObject.cfc:437):437 at mso.clientobject_cfc$cf.udfCall(/var/www/html/www/www.simon.test/mso/ClientObject.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:94):94 at railo.runtime.type.UDFImpl._call(UDFImpl.java:307):307 at railo.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:198):198 at railo.runtime.ComponentImpl._call(ComponentImpl.java:617):617 at railo.runtime.ComponentImpl._call(ComponentImpl.java:499):499 at railo.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1732):1732 at railo.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:738):738 at railo.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1513):1513 at mso.proxyclientobject_cfm$cf._1(/var/www/html/www/www.simon.test/mso/proxyClientObject.cfm:19):19 at mso.proxyclientobject_cfm$cf.udfCall(/var/www/html/www/www.simon.test/mso/proxyClientObject.cfm):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:94):94 at railo.runtime.type.UDFImpl._call(UDFImpl.java:307):307 at railo.runtime.type.UDFImpl.call(UDFImpl.java:211):211 at railo.runtime.ComponentImpl._call(ComponentImpl.java:616):616 at railo.runtime.ComponentImpl._call(ComponentImpl.java:499):499 at railo.runtime.ComponentImpl.call(ComponentImpl.java:1715):1715 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:712):712 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1503):1503 at preparecosting_cfm$cf.call(/var/www/html/www/www.simon.test/prepareCosting.cfm:24):24 at railo.runtime.PageContextImpl.doInclude(PageContextImpl.java:834):834 at railo.runtime.PageContextImpl.doInclude(PageContextImpl.java:781):781 at application_cfc$cf._1(/var/www/html/www/www.simon.test/Application.cfc:177):177 at application_cfc$cf.udfCall(/var/www/html/www/www.simon.test/Application.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:94):94 at railo.runtime.type.UDFImpl._call(UDFImpl.java:307):307 at railo.runtime.type.UDFImpl.call(UDFImpl.java:211):211 at railo.runtime.ComponentImpl._call(ComponentImpl.java:616):616 at railo.runtime.ComponentImpl._call(ComponentImpl.java:499):499 at railo.runtime.ComponentImpl.call(ComponentImpl.java:1715):1715 at railo.runtime.listener.ModernAppListener.call(ModernAppListener.java:388):388 at railo.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:204):204 at railo.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:18):18 at railo.runtime.PageContextImpl.execute(PageContextImpl.java:2167):2167 at railo.runtime.PageContextImpl.execute(PageContextImpl.java:2134):2134 at railo.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:335):335 at railo.loader.servlet.CFMLServlet.service(CFMLServlet.java:29):29 at javax.servlet.http.HttpServlet.service(HttpServlet.java:728):728 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305):305 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210):210 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222):222 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123):123 at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472):472 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171):171 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99):99 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118):118 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407):407 at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:200):200 at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589):589 at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310):310 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145):1145 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615):615 at java.lang.Thread.run(Thread.java:744):744

Unit test + accompanying cfc that can be used to reproduce

javaErrorTest.cfc (Unit test)

component extends='mxunit.framework.TestCase' {
    public void function trySavingLargeNestedStruct() {
        // Prove that it doesn't happen with nested structures
        var nestedStruct = {};
        var nestInMe = nestedStruct;
        // Make a big struct
        var nestedStruct = {};
        var v = ['a','b','c','d','e','f','g','h','i','j','k','l','m','n','o','p','q','r','s','t','u','v','w','x','y','z'];
        for (var i in v) {
            for (var j in v) {
                for (var k in v) {
                    for (var l in v) {
                        nestedStruct[i][j][k][l] = {};
                    }
                }

            }
        }
        debug('Nested struct len = '&len(serialize(nestedStruct)));
        ObjectSave(nestedStruct);
        debug('Nested struct saved without error');
    }
    public void function triggerUTFDataFormatException() {
        // Prove that it happens with objects nested deeply
        var previousLength = 0;
        for (var i=600;i<700;i++) {
            objTest = new TestObject( levels = i );
            var strSerialized = serialize(objTest);
            try {
                ObjectSave(objTest);
            } catch (java.io.UTFDataFormatException e) {
                // Expected place of java.io.UTFDataFormatException
                debug('Levels = '&i-1&' has serialize() length = '&previousLength);
                debug('Levels = '&i&' has serialize() length = '&Len(strSerialized));
                debug(strSerialized);
                debug(e);
                fail('java.io.UTFDataFormatException (expected) error thrown');
            } catch (any e) {
                debug(e);
                fail('Error thrown, not not the expected one');
            }   
            previousLength = Len(strSerialized);
        }
    }
}

TestObject.cfc (Used within the failing test)

component {
    public TestObject function init(
        required numeric levels = 0
    ) {
        variables.a = (arguments.levels > 0)?new TestObject( levels = arguments.levels - 1 ):{};
        return this;
    }
}

Answer 1

The following 2 methods are what I am using in place of ObjectSave and ObjectLoad until the Railo bug is corrected. It seems to function up to a decent level of complexity.

// Replaces ObjectSave
private binary function serializeState(
    required struct inState
) {
    var strSerialized = serialize(arguments.inState);
    return strSerialized.GetBytes();
}

// Replaces ObjectLoad
private struct function deserializeState(
    required binary inState
) {
    var strSerialized = ToString(arguments.inState);
    var stcDeserialized = evaluate(strSerialized);
    return stcDeserialized;
}

Answer 2

Look at the stack trace. It answers all your questions.

java.io.UTFDataFormatException at java.io.ObjectOutputStream$BlockDataOutputStream.writeUTF(ObjectOutputStream.java:2163):2163 at java.io.ObjectOutputStream$BlockDataOutputStream.writeUTF(ObjectOutputStream.java:2006):2006 

A glance at the Javadoc shows that this exception is thrown by writeUTF() if the data to be written is longer than 65535 bytes.

railo.runtime.ComponentImpl.writeExternal(ComponentImpl.java:1975):1975

This is the code that calls writeUTF(). So it appears to be a bug in the railo.runtime.ComponentImpl class. It shouldn't be calling writeUTF() for such a long string.