Performance Regression in Lucee 4

197 views
Skip to first unread message

David Polehonski

unread,
Mar 23, 2016, 9:09:02 AM3/23/16
to Lucee
I have been comparing the performance of Railo Vs Lucee after a test migration of the Mura CMS. Lucee on the whole is running slower with certain parts executing up to 10x slower than Railo. 

I posted on the MuraCMS Group, and I may not be the only one:

An Example of the impact can be seen when comparing the execution time of a specific section of code; see tick count traces below:

Railo - Instantiating a category Bean: Total 2ms
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[findSetters]: categoryBean tickCount: 1 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[findSetters]: CATEGORYMANAGER tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[loopMeta]: CATEGORYMANAGER tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[Done]: CATEGORYMANAGER tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[recursed]: categoryBean tickCount: 1 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[findSetters]: CONTENTUTILITY tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[findSetters]: MAILER tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[loopMeta]: MAILER tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[Done]: MAILER tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[recursed]: CONTENTUTILITY tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[loopMeta]: CONTENTUTILITY tickCount: 0 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[Done]: CONTENTUTILITY tickCount: 1 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[recursed]: categoryBean tickCount: 2 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[recursed]: categoryBean tickCount: 2 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[loopMeta]: categoryBean tickCount: 2 "
"INFO","ajp-bio-8009-exec-1","03/23/2016","11:54:30","","resolveBeanCreate[Done]: categoryBean tickCount: 2 "


Lucee - Instantiating a category Bean: Total 17ms
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[findSetters]: categoryBean tickCount: 1 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[findSetters]: CATEGORYMANAGER tickCount: 0 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[loopMeta]: CATEGORYMANAGER tickCount: 1 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[Done]: CATEGORYMANAGER tickCount: 1 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[recursed]: categoryBean tickCount: 6 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[findSetters]: CONTENTUTILITY tickCount: 0 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[findSetters]: MAILER tickCount: 1 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[loopMeta]: MAILER tickCount: 2 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[Done]: MAILER tickCount: 2 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[recursed]: CONTENTUTILITY tickCount: 5 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[loopMeta]: CONTENTUTILITY tickCount: 5 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[Done]: CONTENTUTILITY tickCount: 6 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[recursed]: categoryBean tickCount: 14 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[recursed]: categoryBean tickCount: 16 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[loopMeta]: categoryBean tickCount: 16 "
"INFO","ajp-nio-8009-exec-8","03/23/2016","11:49:08","","resolveBeanCreate[Done]: categoryBean tickCount: 17 "

Further digging seemes to yield that it was the recursion that took the most time, and a Mission Control seems to think Lucee is spending alot of time in a set of methods called '_duplicate' - Can provide thread dumps if required.

Andrew Dixon

unread,
Mar 23, 2016, 9:11:06 AM3/23/16
to lu...@googlegroups.com
Hi David,

What are the Railo and Lucee version numbers?

Kind regards,

Andrew

--
Love Lucee? Become a supporter and be part of the Lucee project today! - http://lucee.org/supporters/become-a-supporter.html
---
You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/d26b4286-1e11-401d-afd0-0b47f881846d%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

David Polehonski

unread,
Mar 24, 2016, 5:24:58 AM3/24/16
to Lucee
Lucee 4.5.2.018 final & Railo 4.2.1.008 final

I think it is in no small part the fault of the code that is trying to run - its the ioc.cfc of Framework1, but I wouldn't expect such a slow down..

Mark Drew

unread,
Mar 24, 2016, 5:49:17 AM3/24/16
to lu...@googlegroups.com
I think you need to turn debugging on and look at the execution times. Then try and create a test case for it. 

You are working with too many variables to make any useful comparisons. Could be the db driver, could be the beans are not cached could be the wind is going the wrong way. 

Are they on the same machine? Etc etc. All these are factors. 

Mark Drew
- Sent by typing with my thumbs. 

Michael Offner

unread,
Mar 24, 2016, 8:56:38 AM3/24/16
to lucee
First of all +1 of everything Mark Drew said.

What is important to understand that the last Railo version and the first Lucee version had the same code base.
So an option could be to use the first Lucee version (4.5.0.042) you can download here https://bitbucket.org/lucee/lucee/downloads (see at the bottom of the page) and compare that version with Railo.
If you see still a difference, it is unrelated to Lucee, it is only about the environment.
If not you can find out what version is causing this by updating version by version until you see the decrease in the performance.
If you need any help with that, let me know.

Micha




--

David Polehonski

unread,
Mar 31, 2016, 4:41:42 AM3/31/16
to Lucee
o.k, I've run the comparison between Lucee 4.5.0.042 and The latest version, as well as against the last version of Railo, All on the same machine, all using the same application settings, db drivers etc, The Earliest version of Lucee performed worst, with the latest version performing 3x faster. However both are trumped by the last release of Railo..

I agree that a test case is required- any advice on what should be included?

Andrew Dixon

unread,
Mar 31, 2016, 1:57:28 PM3/31/16
to lu...@googlegroups.com
Hi David,

What version of Java is each running on?

Kind regards,

Andrew

On 31 March 2016 at 09:41, 'David Polehonski' via Lucee <lu...@googlegroups.com> wrote:
o.k, I've run the comparison between Lucee 4.5.0.042 and The latest version, as well as against the last version of Railo, All on the same machine, all using the same application settings, db drivers etc, The Earliest version of Lucee performed worst, with the latest version performing 3x faster. However both are trumped by the last release of Railo..

I agree that a test case is required- any advice on what should be included?

--
Love Lucee? Become a supporter and be part of the Lucee project today! - http://lucee.org/supporters/become-a-supporter.html
---
You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/c1877aab-8dd2-4efa-aab8-31605d2ff202%40googlegroups.com.

Andrew Dixon

unread,
May 4, 2016, 12:26:00 PM5/4/16
to lu...@googlegroups.com
Hi David,

We have had a similar issue with Mura today and in the end it appeared to be the combination of Lucee 4.5 and Java 7, once we move Lucee/Tomcat up to running on Java 8 the performance increase was massive. Did you ever look into this any further?

Kind regards,

Andrew

Reply all
Reply to author
Forward
0 new messages