Anyone have any more ideas as to what this could be?
I am 99% sure the *underlying *issue is something to do with ORM- it always
happens around ORM accesses.
But I can’t even debug it as Lucee is not giving me correct debug
information and is telling me nothing is wrong and the page is loading
quickly! After it has spent MINUTES churning away on my laptop. It is lying
to me!
I’m seeing it again now on another page which loads a few entities. This
page is really inconsistent- sometimes it will run for 10 minutes at 100%
CPU before failing with a Java Out of Memory error
Lucee 4.5.2.018 Error (java.lang.OutOfMemoryError)
Message Java heap space
Cause java.lang.OutOfMemoryError
This I think is to do with the error handling and may involve FW/1 or our
custom code’s error handling- the above error was actually in the “dump”
tag which was failing trying to dump a variable.
On another reload, it pegs the CPU for at over 10 minutes (it was
definitely longer than the 300 seconds reported) before deciding that
entityLoad has timed out:
request (path: …1) has run into a timeout (300 seconds) and has been
stopped.
61: rc.companies = entityLoad(“Company”, {active = 1}, “name asc”);
On another reload, it runs fine and comes back pretty much instantly!
It is completely random, sometimes it loads fine, sometimes it pegs the CPU
for ten minutes and fails. It works 100% of the time on Railo.
OK- so that is the underlying issue. But what I am concerned about here is
the Lucee debug output.
I then turn on debugging and reload, it takes well over a minute but Lucee
is telling me the page processed in a bit over a second. IT DIDN’T! No you
didn’t! Second my ass, you were churning away on this for five minutes. I
could hear the fan! I could see the Lucee process pegged at 100% CPU! 1.3
seconds my ass that is a barefaced lie!
1,232.145 ms Application
129.700 ms Startup/Compilation
0.000 ms Query
1,361.845 ms Total
Looking at the details this is the stuff with repeated ORM accesses- is
this a problem? Is it related? Is the total accurate? I don’t know. But my
hunch is it has something to do with these ORM entities with several
hundred records, I always see this issue in this context.
0.64 45 0.014 \WEB-INF\lucee\context\Component.cfc
1.328 38 0.035 \components\helpers\model.cfc
6.405 942 0.007 \modules\companies\models\Member2.cfc$getId
0.189 249 0.001 \modules\companies\models\Company.cfc$getId
0.646 942 0.001 \modules\companies\models\Member2.cfc$getCompany
0.73 1191 0.001 \modules\companies\models\Company.cfc$getName
0.416 942 0 \modules\companies\models\Member2.cfc$getFirstname
0.331 942 0 \modules\companies\models\Member2.cfc$getLastname
0.279 942 0 \modules\companies\models\Member2.cfc$getMiddleinitial
This page works, no issues, on our production server running Railo.
If anyone had any ideas as to what the issue could be that would be great,
I’m at the point where I am really thinking of just giving up on Lucee
entirely and going back to an old version of Railo to match our production
environment and giving up the idea of transitioning that over to Lucee, it
is very frustrating and I can’t even get information out of Lucee that
seems to gel with the actual behaviour I’m witnessing.
One key difference between the configuration of the two is that I have
this.ormsettings.autoManageSession= “true” on the Railo server and
this.ormsettings.autoManageSession= “false” on Lucee, due to some other bug
with Lucee’s ORM handling which was apparently introduced in Railo just
before the fork (bug #77 I think).
Note I am on Lucee 4.5 because Lucee 5 has an issue with FW/1.
Any ideas appreciated, if there was anything that could even just point me
in the right direction with this that would be fantastic.
Ivan