http://coldfusion.com logo
Join Slack
Powered by
Is anyone else finding that objectSave() and seria...
# lucee
d
Is anyone else finding that objectSave() and serialize() are broken in 5.3.9.133+? When I try to serialize a component, I end up with a stack trace that looks like:
Copy code
lucee.runtime.exp.NativeException: can't serialize Object of type [ org.apache.tomcat.util.log.SystemLogHandler ]
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:562)
 	at lucee.runtime.converter.ScriptConverter._serializeStruct(ScriptConverter.java:204)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:519)
 	at lucee.runtime.converter.ScriptConverter._serializeComponent(ScriptConverter.java:351)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:512)
 	at lucee.runtime.converter.ScriptConverter._serializeStruct(ScriptConverter.java:204)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:519)
 	at lucee.runtime.converter.ScriptConverter._serializeStruct(ScriptConverter.java:204)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:519)
 	at lucee.runtime.converter.ScriptConverter._serializeComponent(ScriptConverter.java:351)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:512)
 	at lucee.runtime.converter.ScriptConverter._serializeStruct(ScriptConverter.java:204)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:519)
 	at lucee.runtime.converter.ScriptConverter._serializeComponent(ScriptConverter.java:351)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:512)
 	at lucee.runtime.converter.ScriptConverter._serializeStruct(ScriptConverter.java:204)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:519)
 	at lucee.runtime.converter.ScriptConverter._serializeComponent(ScriptConverter.java:351)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:512)
 	at lucee.runtime.converter.ScriptConverter._serializeComponent(ScriptConverter.java:351)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:512)
 	at lucee.runtime.converter.ScriptConverter._serializeStruct(ScriptConverter.java:204)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:519)
 	at lucee.runtime.converter.ScriptConverter._serializeComponent(ScriptConverter.java:351)
 	at lucee.runtime.converter.ScriptConverter._serialize(ScriptConverter.java:512)
 	at lucee.runtime.converter.ScriptConverter.serialize(ScriptConverter.java:611)
 	at lucee.runtime.functions.dynamicEvaluation.Serialize.call(Serialize.java:35)
I'm not sure why 
org.apache.tomcat.util.log.SystemLogHandler
is trying to be serialized, but it appears to be related to how the component gets compiled.
z
does it happen with 5.3.8 or is this a new regression, i know there was a change with serializing components / udfs recently
d
I'm not sure and I really can't test it, because our app requires 5.3.9.x. It's not every component that's throwing this error. I'm trying to figure out a simple use case. I do know that 
org.apache.tomcat.util.log.SystemLogHandler
isn't used in our codebase, but there's obviously some dependency that does rely on it.
z
ok file a bug
d
I've got several fixes for the ehcache extension too
This serialization issue is part of why distributed cache is broken
b
I've often times wished there was better debugging for serialization issues since often times the object that fails serialization can be nested many levels deep within the actual object you were storing.
You can see from that stack trace, it looks to be 6 CFCs possibly nested inside of each other? (counting the recursive 
_serializeComponent
calls
d
@bdw429s I agree! I'm trying to debug using logpoints in VSCode inside the ScrptConverter._serialize() method, but there's so much nested serialization it seems to be timing out the debugger and things hang.
b
To track this down, I usually catch the error and look at the top level object being serialized, then look at all the references it has and delete them one by one until the error goes away to trace down the path to the bad object. It's time consuming, but will help
Some trace level debugging that would output the names of the object path it was following would be handy, but I don't think that exists, so you have to mostly brute force find it.
I did a bunch of this recently on a client codebase using TransferORM that I converted to be able to use Lucee and an external Redis cache. I had to break a LOT of hard references to the transfer framework to get the entities to serialize, but it worked eventually.
A great enhancement to Lucee actually would be to modify it's serializer classes to build up a string that represented the "path" to the object being serialized and include it in any error messages.
Then it could say something like
Copy code
object [customer.variables.addresss.this.logger.sessioni.requestContext.variables.Coldbox.variables.foo] could not be serialized
or something like that. Would be worth gold here.
d
If I need to patch the serialize method, I'll look at doing that. It's already passing around a string builder to track the serialized input, so that wouldn't be very hard.
b
Dang, it's halfway there! 🙂
If you've never built Lucee, it's not that hard. You can use the Ant method. Just cd into the 
loader
directory and run
Copy code
ant fast
About a minute later you have an 
.lco
file you can drop in the deploy folder and you're ready to test.
I actually automate it with a CommandBox package script similar to this 
box.json
Copy code
{
  "luceeSrcDir": "D:/docs/GitHub/Lucee/",
  "scripts": {
    "compile": "echo 'ant -buildfile ${@luceeSrcDir}loader/build.xml fast' | run && cp '${@luceeSrcDir}loader/target/*.lco' '${serverinfo.serverHomeDirectory}/WEB-INF/lucee-server/deploy/'"
  }
}
Where 
D:/docs/GitHub/Lucee/
is where my Lucee repo is located and I'm using a CommandBox server, so I use a CommandBox env var to find the server home dynamically. ( 
${serverinfo.serverHomeDirectory}
)
Then at the top of my test page, i have this code to force Lucee to suck in the lco file immediately
Copy code
createObject( 'java', 'lucee.runtime.config.DeployHandler' ).deploy( getPageContext().getConfig().getConfigServer( 'password' ), false );
"password" is my server context password for Lucee
So, after making my changes, I just run
Copy code
run-script compile
in CommandBox, and then when it finishes, refresh my test page. I did all the QoQ changes this way and it's a pretty efficient workflow (for a compiled language! 😆 )
d
Ironically, it appears what's causing the serializer to break is ConsoleAppender.cfc in LogBox 😞
Ok, I think I've simplified the example:
Copy code
component {
	public any function init(){
		instance.out = createObject( "java", "java.lang.System" ).out;

		return this;
	}
}
If you save that as x.cfc and then try to run:
Copy code
obj = new x();
Serialize(obj);
It will throw the 
org.apache.tomcat.util.log.SystemLogHandler
error.
(@bdw429s we're using a standalone instance of Cachebox 4.3.0, which has LogBox integrated.)
BTW - If the 
ScrptConverter._serialize()
just wrote the 
sb
StringBuilder error log before the exception is thrown, that would help a lot. For example, as it gives you the place it choked. For example, here's the output of the above example code from above (although my names were a little different):
Copy code
"evaluateComponent("_test","c31d231165a410c67a9a8c57da575e88",{},{"INSTANCE":{"OUT":"
This pretty clearly tells you the error is in serializing the 
OUT
key in the 
INSTANCE
variable.
b
Yeah, that could be cleaned up, but that would be much more helpful
I'm guessing Tomcat is swapping out Java's 
out
printbuffer with one of its own (CommandBox does a similar thing) , but there's not going to be a really good answer to this
Serializing CFCs is wrought with issues like this and most people don't recommend doing it at all, or only doing very simple CFCs
If you you need to serialize CFCs, the only reliable way I've found is to detach all hard references to other objects and replace them with getting methods or providers.
And you also need to be aware all methods mixed in from any sort of DI framework like WireBox or ColdSpring will be LOST when you do this.
d
@bdw429s, I agree, it does appear that Tomcat is dynamically replacing System.out with it's own logging (which make sense, being you're actually sending that to Tomcat's logs). While the root serialization issue would be hard/impossible to solve, the ehCache extension is serializing code when it doesn't have to. It's always serializing variables when running in distributed mode, but I believe it really only needs to do that when the "Via Copy" options are selected. When the "Via Copy" options are not selected, then it should be just marking items to be removed from cache when a put/update happens, so there should be no reason to serialize code to put it in the cache.
I filed the following issue for this: https://luceeserver.atlassian.net/browse/LDEV-3997
👍 1
b
I don't think that's an actionable ticket FWIW
At the end of the day, you can't serialize a non-serializable object.
There's just not way around it. It really boils down to application design
But I do think a ticket to improve the error message would be useful.
d
@bdw429s I also filed an enhancement for better reporting of serialization errors: https://luceeserver.atlassian.net/browse/LDEV-3998 As for the previous issue being resolvable, I agree there's probably nothing that can be done. I wanted to log the issue though, just in case someone smarter than me had a better idea. Like maybe non-serializable components could be ignored. Maybe there's some nomenclature that could be added to specify ignoring the variable/property via serialization. If nothing else, I wanted to document the issue for someone else that runs into a similar issue.
On the positive side of things, I think I have resolved: https://luceeserver.atlassian.net/browse/LDEV-3279
5 Views
Open in Slack
PreviousNext
Powered by