Performance Regression in Lucee 4

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:
https://groups.google.com/forum/#!topic/mura-cms-developers/wICxQnkuatE
https://groups.google.com/forum/#!topic/mura-cms-developers/fXBgLQQ_ajE

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.

Hi David,

What are the Railo and Lucee version numbers?

Kind regards,

Andrew
about.me http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.orgOn 23 March 2016 at 13:09, ‘David Polehonski’ via Lucee < lucee@googlegroups.com> wrote:

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:
Redirecting to Google Groups
Redirecting to Google Groups

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.


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/d26b4286-1e11-401d-afd0-0b47f881846d%40googlegroups.com
https://groups.google.com/d/msgid/lucee/d26b4286-1e11-401d-afd0-0b47f881846d%40googlegroups.com?utm_medium=email&utm_source=footer
.
For more options, visit https://groups.google.com/d/optout.

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.> On 24 Mar 2016, at 09:24, ‘David Polehonski’ via Lucee lucee@googlegroups.com wrote:

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…

On Wednesday, March 23, 2016 at 1:11:06 PM UTC, Andrew Dixon wrote:
Hi David,

What are the Railo and Lucee version numbers?

Kind regards,

Andrew
about.me - mso - Lucee Association Member

On 23 March 2016 at 13:09, ‘David Polehonski’ via Lucee lu...@googlegroups.com wrote:
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:
Redirecting to Google Groups
Redirecting to Google Groups

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.

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.


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/0dcbe1ac-c2de-4b7b-88bd-391e92043496%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

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.

MichaOn Wed, Mar 23, 2016 at 2:09 PM, ‘David Polehonski’ via Lucee < lucee@googlegroups.com> wrote:

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:
Redirecting to Google Groups
Redirecting to Google Groups

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.


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/d26b4286-1e11-401d-afd0-0b47f881846d%40googlegroups.com
https://groups.google.com/d/msgid/lucee/d26b4286-1e11-401d-afd0-0b47f881846d%40googlegroups.com?utm_medium=email&utm_source=footer
.
For more options, visit https://groups.google.com/d/optout.

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…On Wednesday, March 23, 2016 at 1:11:06 PM UTC, Andrew Dixon wrote:

Hi David,

What are the Railo and Lucee version numbers?

Kind regards,

Andrew
about.me http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.org

On 23 March 2016 at 13:09, ‘David Polehonski’ via Lucee < lu...@googlegroups.com <javascript:>> wrote:

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:
Redirecting to Google Groups
Redirecting to Google Groups

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.


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 <javascript:>.
To post to this group, send email to lu...@googlegroups.com <javascript:>
.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/d26b4286-1e11-401d-afd0-0b47f881846d%40googlegroups.com
https://groups.google.com/d/msgid/lucee/d26b4286-1e11-401d-afd0-0b47f881846d%40googlegroups.com?utm_medium=email&utm_source=footer
.
For more options, visit https://groups.google.com/d/optout.

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?

Hi David,

What version of Java is each running on?

Kind regards,

Andrew
about.me http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.orgOn 31 March 2016 at 09:41, ‘David Polehonski’ via Lucee < lucee@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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/c1877aab-8dd2-4efa-aab8-31605d2ff202%40googlegroups.com
https://groups.google.com/d/msgid/lucee/c1877aab-8dd2-4efa-aab8-31605d2ff202%40googlegroups.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

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
about.me http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.orgOn 31 March 2016 at 18:57, Andrew Dixon <@Andrew_Dixon> wrote:

Hi David,

What version of Java is each running on?

Kind regards,

Andrew
about.me http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.org

On 31 March 2016 at 09:41, ‘David Polehonski’ via Lucee < lucee@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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/c1877aab-8dd2-4efa-aab8-31605d2ff202%40googlegroups.com
https://groups.google.com/d/msgid/lucee/c1877aab-8dd2-4efa-aab8-31605d2ff202%40googlegroups.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.