I found the Groovy SimpleTemplateEngine is so slow
Tin
issue, when checking the HTML source code, I found the TemplateServlet
always spend lots of time to make the HTML.
Then I write simple testing code to compare Groovy
SimpleTemplateEngine, FreeMaker and Velocity, the result let me
surprised:
Velocity Template make=36 ms
FreeMaker Template make=60 ms
Groovy Template make=184 ms
The code of testing gtpl, flt and vm are almost the same:
<% purchases.each { purchase -> %>
${purchase.title} ${purchase.createdTime}
<% } %>
<#list purchases as purchase>
${purchase.title} ${purchase.createdTime?string("yyyy-MM-dd")}
</#list>
#foreach( $purchase in $purchases )
$purchase.title $purchase.createdTime
#end
Maybe I should rewrite my view by FreeMaker or Velocity, but I like
using Groovy and I have written lots of gtpl for my project, could you
give some suggestions ?
Thanks very much in advance !!!
Jeff Schwartz
Jeff
--
Vous recevez ce message, car vous êtes abonné au groupe Google Groupes Gaelyk.
Pour envoyer un message à ce groupe, adressez un e-mail à gae...@googlegroups.com.
Pour vous désabonner de ce groupe, envoyez un e-mail à l'adresse gaelyk+un...@googlegroups.com.
Pour plus d'options, consultez la page de ce groupe : http://groups.google.com/group/gaelyk?hl=fr
--
--
Jeff
Guillaume Laforge
The templates are compiled the first time, but are faster on further
invocations of the template.
Could you calculate without the compilation time? (ie. count times for
n hits but not counting the first hit time).
> --
> Vous recevez ce message, car vous êtes abonné au groupe Google Groupes Gaelyk.
> Pour envoyer un message à ce groupe, adressez un e-mail à gae...@googlegroups.com.
> Pour vous désabonner de ce groupe, envoyez un e-mail à l'adresse gaelyk+un...@googlegroups.com.
> Pour plus d'options, consultez la page de ce groupe : http://groups.google.com/group/gaelyk?hl=fr
>
>
--
Guillaume Laforge
Groovy Project Manager
Head of Groovy Development at SpringSource
http://www.springsource.com/g2one
Tin
Thanks for your quickly reply and suggestions, we have done more
testing.
You are right, if I put the testing in a loop, groovy template will be
faster on further :
Velocity Template make=38 ms
FreeMaker Template make=85 ms
Groovy Template make=208 ms
Velocity Template make=4 ms
FreeMaker Template make=4 ms
Groovy Template make=15 ms
Velocity Template make=7 ms
FreeMaker Template make=5 ms
Groovy Template make=9 ms
...
It looks like that groovy template is just a little slower than
Velocity or FreeMaker.
But I still doesn't have idea why the TemplateServlet always need lots
of time to make the result,
just like the templates need to be compiled every time.
You can check the source code of http://gaelyk.appspot.com/ or
http://gaelyk.appspot.com/tutorial,
and notice the logs of TemplateServlet, you will often found log
messages like:
<!-- Generated by Groovy TemplateServlet [create/get=2850 ms, make=585
ms] -->
<!-- Generated by Groovy TemplateServlet [create/get=251 ms, make=610
ms] -->
...
I think most content of this site are static, so the response time is
much slower.
In our project, a very simple list page that contains just 10 records
often need over 4-8 sec. to make the result.
I had tried to use fake data instead of fetching from JPA, but the
time just a litter faster.
So I think the real reason of this bad performance is GAE runtime or
TemplateServlet has some limitations.
Maybe I should try to use memcache to store the TemplateCacheEntry or
do something to compile those templates in advanced.
Thank you very much again !!!
Guillaume Laforge
On Fri, May 28, 2010 at 09:17, Tin <tin....@gmail.com> wrote:
> Dear Jeff & Guillaum:
>
> Thanks for your quickly reply and suggestions, we have done more
> testing.
> You are right, if I put the testing in a loop, groovy template will be
> faster on further :
>
> Velocity Template make=38 ms
> FreeMaker Template make=85 ms
> Groovy Template make=208 ms
This is probably the first hit, after the application was first loaded
(locally on your dev env, on after a "loading request" on Google App
Engine).
So this takes a bit more time to compile and cache the template.
> Velocity Template make=4 ms
> FreeMaker Template make=4 ms
> Groovy Template make=15 ms
>
> Velocity Template make=7 ms
> FreeMaker Template make=5 ms
> Groovy Template make=9 ms
Then, once in compiled and in cache, it's already much snappier, which
is good -- even if slower than Velocity or FreeMarker.
> It looks like that groovy template is just a little slower than
> Velocity or FreeMaker.
Right.
> But I still doesn't have idea why the TemplateServlet always need lots
> of time to make the result,
> just like the templates need to be compiled every time.
Unless GAE does a "loading request" because your site hasn't yet too
much traffic, otherwise, when in compiled and in cache, it's not bad
at all.
> You can check the source code of http://gaelyk.appspot.com/ or
> http://gaelyk.appspot.com/tutorial,
> and notice the logs of TemplateServlet, you will often found log
> messages like:
>
> <!-- Generated by Groovy TemplateServlet [create/get=2850 ms, make=585
> ms] -->
> <!-- Generated by Groovy TemplateServlet [create/get=251 ms, make=610
> ms] -->
> ...
Again probably you came when the app wasn't used much, GAE had
disposed the instances, and after that made a load request to spin up
a new VM and servlet container, and also initializing Groovy as it
loaded the templates, etc.
For example, just before writing this email, I went to the two pages
you mentioned and saw respectively:
<!-- Generated by Groovy TemplateServlet [create/get=1 ms, make=1 ms] -->
<!-- Generated by Groovy TemplateServlet [create/get=112 ms, make=14 ms] -->
and
<!-- Generated by Groovy TemplateServlet [create/get=1 ms, make=1 ms] -->
<!-- Generated by Groovy TemplateServlet [create/get=0 ms, make=24 ms] -->
which isn't bad at all in my book.
But at that time, the application was running and hot, so I didn't
suffer from GAE's loading requests.
In the case of those pages, also, there's some include going on, so
the second time also includes the time of the first template!
> I think most content of this site are static, so the response time is
> much slower.
I should actually make those page normal static pages, since there's
no dynamic aspect going on :-)
As GAE serves static content without needing those loading requests,
that would make the site more responsive.
> In our project, a very simple list page that contains just 10 records
> often need over 4-8 sec. to make the result.
Of first load of the page, and on subsequent loads?
> I had tried to use fake data instead of fetching from JPA, but the
> time just a litter faster.
> So I think the real reason of this bad performance is GAE runtime or
Definitely GAE's loading requests, for which we can't do much about.
> TemplateServlet has some limitations.
It's certainly not be refined over the years like dedicated projects
like FreeMarker or Velocity, I guess, but once loaded and in cache,
the templates have some okay results, at least from what I see.
> Maybe I should try to use memcache to store the TemplateCacheEntry or
> do something to compile those templates in advanced.
You could try storing TemplateCacheEntry in memcache, and I'd be
interested in hearing about the results you get.
We've been discussing those things a bit already on the google group here.
> Thank you very much again !!!
My pleasure :-)
Guillaume
>
>
> On 5月28日, 上午3時11分, Guillaume Laforge <glafo...@gmail.com> wrote:
>> Your results are including or excluding the compilation?
>> The templates are compiled the first time, but are faster on further
>> invocations of the template.
>> Could you calculate without the compilation time? (ie. count times for
>> n hits but not counting the first hit time).
>
Tin
I have some news:
1. I can't using memcache to store the TemplateCacheEntry, because
SimpleTemplate isn't Serializable
2. If I mark following code in the GaelykTemplateServlet.groovy, the
performance is improved but I don't know why :
use (groovyx.gaelyk.GaelykCategory) { ... }
Guillaume Laforge
2010/5/28 Tin <tin....@gmail.com>:
> Hi all:
>
> I have some news:
>
> 1. I can't using memcache to store the TemplateCacheEntry, because
> SimpleTemplate isn't Serializable
Hmm, right.
Well, as I expected such changes will require changes in Groovy
itself, not just at the Gaelyk level.
> 2. If I mark following code in the GaelykTemplateServlet.groovy, the
> performance is improved but I don't know why :
> use (groovyx.gaelyk.GaelykCategory) { ... }
That's actually what makes Gaelyk magic.
Without that line, you don't have all the services injected, no the
syntax sugar around the GAE SDK, etc.
So, yes, it's faster, but it's not really Gaelyk anymore, and you
could as well use pure Groovy (and its GroovyServlet and
TemplateServlet) instead.
> Thank you very much again !!!
>
Tin
>> often need over 4-8 sec. to make the result.
> Of first load of the page, and on subsequent loads?
page : http://goo.gl/QF21 (please feel free those are testing data)
The default paging size is 10, there are only 29 recodes in the
Purchase kind big-table, but when browsing data the performance is so
bad.
I have used AJAX to show items data or load cost data but it still
slow. ><||
Guillaume Laforge
>>> In our project, a very simple list page that contains just 10 records
>>> often need over 4-8 sec. to make the result.
>
>> Of first load of the page, and on subsequent loads?
>
> nn.. almost every time,
Really?
So there's something else going on!
For instance, the Groovy Web Console does fetch the recent scripts
published on each pages, and it's not that slow.
http://groovyconsole.appspot.com
> if you have time you can check this testing
> page : http://goo.gl/QF21 (please feel free those are testing data)
> The default paging size is 10, there are only 29 recodes in the
> Purchase kind big-table, but when browsing data the performance is so
> bad.
> I have used AJAX to show items data or load cost data but it still
> slow.
I only get:
Error: Action Servlet Error: URI: '/purchase/list.do': Action
processing failed. This request (d23f65a56d6bc483) started at
2010/05/28 10:22:24.968 UTC and was still executing at 2010/05/28
10:22:53.475 UTC.java.lang.Object.wait(Native Method)
when hitting the URL you gave me :-(
Guillaume
Otto
I'm unclear about something...
On May 28, 5:06 am, Guillaume Laforge <glafo...@gmail.com> wrote:
> This is probably the first hit, after the application was first loaded
> (locally on your dev env, on after a "loading request" on Google App
> Engine).
> So this takes a bit more time to compile and cache the template.
If the template is being cached as you say, why is there further need
to cache templates in memcache like Tin is saying?
I want to determine if groovy/gaelyk is appropriate for a relatively
large website and I'm concerned about these caching issues.
thanks,
Otto
Guillaume Laforge
On Sun, May 30, 2010 at 20:02, Otto <von...@gmail.com> wrote:
> Hi,
>
> I'm unclear about something...
>
> On May 28, 5:06 am, Guillaume Laforge <glafo...@gmail.com> wrote:
>> This is probably the first hit, after the application was first loaded
>> (locally on your dev env, on after a "loading request" on Google App
>> Engine).
>> So this takes a bit more time to compile and cache the template.
>
> How does it cache the template? Is it using memcache?
Nope, it's basically using Groovy's own cache.
Actually, here's how it's working.
For a groovlet, it's just a Groovy script, hence a Groovy class, so
once it's compiled, it's available in the classloader, so it's "in the
cache" in the same sense that java.lang.String is in the cache, ie.
loaded in the VM memory.
For a template, there's an additional step, as a template is first
translated into a Groovy script, and then that script is compiled like
Groovlets.
> If the template is being cached as you say, why is there further need
> to cache templates in memcache like Tin is saying?
Caching may be useful for GAE's "loading requests".
When a new VM is spined up, perhaps it'd be snappier to get a groovlet
or template from memcache.
But for low-trafic sites, the groovlet or template would not stick in
memcache for long, so it won't help much anyway.
So far, it's not yet clear if it's worth investigating or not, as we
don't know the outcome.
Perhaps such caching won't help much, I can't tell.
> I want to determine if groovy/gaelyk is appropriate for a relatively
> large website and I'm concerned about these caching issues.
What's nice with Groovy/Gaelyk is that you don't have too much
overhead, compared to solutions using X various layer needing their
own initialization (ie. a container, an ORM layer, the JPA/JDO
initialization, etc...). So its lightweight-ness is interesting IMHO.
Also it depends on what you mean by "large website".
Perhaps you can tell me a bit more about what you had in mind?
Tin
We have done more testing and maybe we knew what's happen to make this
performance issue:
1. We used the Memcache to store our i18n messages, I found if there
are many i18n message in one page, the performance will be much worse.
So we change to use LRUMap that will make compiled template running
faster (less than 1 sec)
2. I set the default logging level to INFO and monitor the logs of
GAE, I found GAE does a "loading request" in a short period of time:
05-30 11:19PM 49.838 javax.servlet.ServletContext log:
TemplateServlet: Parsing init parameters... ----> less than 110 sec.
05-30 11:18PM 06.467 javax.servlet.ServletContext log:
TemplateServlet: Parsing init parameters...
...
05-30 11:03PM 08.186 javax.servlet.ServletContext log:
TemplateServlet: Parsing init parameters... ----> less than 20 sec.
05-30 11:02PM 38.921 javax.servlet.ServletContext log:
TemplateServlet: Parsing init parameters...
...
Because the TemplateServlet was reloaded all of the cached
templates are miss, the performance is worse again. ><|||
I have tried to override the getTemplate(..) method of TemplateServlet
by using "private final static LRUMap" as cache, but it's useless,
every time the TemplateServlet was reloaded the cache will be also
cleared. (I don't know why, it's static member).
By the way if using Velocity as template engine, there's the same
performance issue, but the compiled and making time of Velocity are
less than Groovy, when GAE does a "loading request" the waiting time
is a little faster.
We will still try other way to solve this issue, thanks much ~~
Tin
The followings are detail logs when GAE dose a "loading request" :
05-31 12:07AM 20.842 ... Parsing init parameters...
05-31 12:07AM 20.842 ... (Abstract) init done. Listing some parameter
name/value pairs:
05-31 12:07AM 20.842 ... verbose = true
05-31 12:07AM 20.842 ... reflection = false
05-31 12:07AM 20.842 ... logGROOVY861 = false
05-31 12:07AM 20.842 ... resource.name.regex = null
05-31 12:07AM 20.842 ... resource.name.replacement = null
05-31 12:07AM 20.842 ... Servlet
com.liyue.gaelyk.GaelykTemplateServlet initialized on class
groovy.text.SimpleTemplateEngin
05-31 12:07AM 21.163 ... Creating/getting cached template...
05-31 12:07AM 21.214 ... Looking for cached template by key "/.../
purchase_list.gtpl
05-31 12:07AM 21.266 ... Cache miss.
05-31 12:07AM 21.266 ... Creating new template from file /.../
purchase_list.g
05-31 12:07AM 24.971 ... Created and added template to cache.
[key=/.../purchase_list.gtpl
05-31 12:07AM 25.916 ... Making template "purchase_list.gtpl"...
05-31 12:07AM 25.953 ... Creating/getting cached template...
05-31 12:07AM 25.954 ... Looking for cached template by key "/.../
includes/header.gtpl
05-31 12:07AM 25.954 ... Cache miss.
05-31 12:07AM 25.954 ... Creating new template from file /.../includes/
header
05-31 12:07AM 26.209 ... Created and added template to cache.
[key=/.../includes/header.gtpl
05-31 12:07AM 26.217 ... Making template "header.gtpl"...
05-31 12:07AM 26.283 ... Creating/getting cached template...
05-31 12:07AM 26.284 ... Looking for cached template by key "/.../css/
form.css.gtpl
05-31 12:07AM 26.284 ... Cache miss.
05-31 12:07AM 26.284 ... Creating new template from file /.../css/
form.css.gt
05-31 12:07AM 27.019 ... Created and added template to cache.
[key=/.../css/form.css.gtpl
05-31 12:07AM 27.020 ... Making template "form.css.gtpl"...
05-31 12:07AM 27.338 ... Template "form.css.gtpl" request responded.
[create/get=735 ms, make=317 ms]
05-31 12:07AM 27.340 ... Template "header.gtpl" request responded.
[create/get=255 ms, make=1123 ms]
05-31 12:07AM 27.355 ... Creating/getting cached template...
05-31 12:07AM 27.357 ... Looking for cached template by key "/.../
menu.gtpl"
05-31 12:07AM 27.357 ... Cache miss.
05-31 12:07AM 27.357 ... Creating new template from file /.../
menu.gtpl...
05-31 12:07AM 27.476 ... Created and added template to cache.
[key=/.../menu.
05-31 12:07AM 27.479 ... Making template "menu.gtpl"...
05-31 12:07AM 27.496 ... Template "menu.gtpl" request responded.
[create/get=121 ms, make=16 ms]
05-31 12:07AM 28.705 ... Creating/getting cached template...
05-31 12:07AM 28.706 ... Looking for cached template by key "/.../
paging.gtpl
05-31 12:07AM 28.706 ... Cache miss.
05-31 12:07AM 28.706 ... Creating new template from file /.../
paging.gtpl...
05-31 12:07AM 28.991 ... Created and added template to cache.
[key=/.../paging.gtp
05-31 12:07AM 28.993 ... Making template "paging.gtpl"...
05-31 12:07AM 29.112 ... Template "paging.gtpl" request responded.
[create/get=286 ms, make=119 ms]
05-31 12:07AM 29.124 ... Creating/getting cached template...
05-31 12:07AM 29.126 ... Looking for cached template by key "/.../
menu.gtpl"
05-31 12:07AM 29.136 ... LRU cache hit! Hit 1 since Mon May 31
07:07:27 UTC 2010
05-31 12:07AM 29.138 ... Making template "menu.gtpl"...
05-31 12:07AM 29.140 ... Template "menu.gtpl" request responded.
[create/get=10 ms, make=2 ms]
05-31 12:07AM 29.141 ... Creating/getting cached template...
05-31 12:07AM 29.141 ... Looking for cached template by key "/.../
includes/footer.gtpl
05-31 12:07AM 29.142 ... Cache miss.
05-31 12:07AM 29.142 ... Creating new template from file /.../includes/
footer.gtpl
05-31 12:07AM 29.251 ... Created and added template to cache.
[key=/.../inclu
05-31 12:07AM 29.253 ... Making template "footer.gtpl"...
05-31 12:07AM 29.253 ... Template "footer.gtpl" request responded.
[create/get=110 ms, make=0 ms]
05-31 12:07AM 29.253 ... Template "purchase_list.gtpl" request
responded. [create/get=3807 ms, make=3337 ms]
05-31 12:07AM 29.254 <stdout>: com.liyue.web.purchase.List spend :
17484 ms ----> Oh~~ over 17 sec. my boss will kill us..
Otherwise if the TemplateServlet is warm up:
05-30 11:19PM 06.996 ... Creating/getting cached template...
....
05-30 11:19PM 07.578 <stdout>: com.liyue.web.purchase.List spend : 686
ms ----> less than 1 sec. it's perfect !!!
Guillaume Laforge
On Mon, May 31, 2010 at 09:01, Tin <tin....@gmail.com> wrote:
> Hi all:
>
> We have done more testing and maybe we knew what's happen to make this
> performance issue:
>
> 1. We used the Memcache to store our i18n messages, I found if there
> are many i18n message in one page, the performance will be much worse.
> So we change to use LRUMap that will make compiled template running
> faster (less than 1 sec)
>
> 2. I set the default logging level to INFO and monitor the logs of
> GAE, I found GAE does a "loading request" in a short period of time:
>
> 05-30 11:19PM 49.838 javax.servlet.ServletContext log:
> TemplateServlet: Parsing init parameters... ----> less than 110 sec.
> 05-30 11:18PM 06.467 javax.servlet.ServletContext log:
> TemplateServlet: Parsing init parameters...
> ...
> 05-30 11:03PM 08.186 javax.servlet.ServletContext log:
> TemplateServlet: Parsing init parameters... ----> less than 20 sec.
> 05-30 11:02PM 38.921 javax.servlet.ServletContext log:
> TemplateServlet: Parsing init parameters...
> ...
20 seconds is really not much.
Usually, it seems GAE kills the containers after a minute or more for
low-trafficed apps.
But for more popular site, I've heard performance even improves, as if
it analyzed the characteristics of the app, and gave it better VMs or
something like that.
I wish they were not so secretive about their architecture and logic :-)
> Because the TemplateServlet was reloaded all of the cached
> templates are miss, the performance is worse again. ><|||
Seems logical, unfortunately.
> I have tried to override the getTemplate(..) method of TemplateServlet
> by using "private final static LRUMap" as cache, but it's useless,
> every time the TemplateServlet was reloaded the cache will be also
> cleared. (I don't know why, it's static member).
Yeah, but static member or not, if they stop / start the container, or
even the VM, everything starts anew, so nothing sticks in the cache.
What's interesting with memcache is that it can keep stuff even when
no VM and container are loaded for your apps, but it seems it's only
true for simple objects (ie. the basic structures GAE can store
natively in memcache), but even if we'd put "rich" objects like our
templates, they may die anyway once the container is unloaded, so
going the memcache way may not help much in the end.
> By the way if using Velocity as template engine, there's the same
> performance issue, but the compiled and making time of Velocity are
> less than Groovy, when GAE does a "loading request" the waiting time
> is a little faster.
>
> We will still try other way to solve this issue, thanks much ~~
Thanks a lot for updating us on this topic!
Looking forward to hearing more of your experiments.
Tin
I have found a method to played a trick on GAE and it works, although
I don't think it's a model answer.
For keeping the TemplateServlet is always hot, we need hit our web
site frequently, so I think the "task queue" can help me:
1. Writing a "WarmUp" action as a task worker, it will add a new task
to request itself after a period then forward to a gtpl page.
2. Writing a context listener, it will request the "WarmUp" action
when this web app first be requested.
When I check the GAE logs, I found my GAE app is always keeping hot:
05-31 09:06AM 47.751 ... Creating/getting cached template...
05-31 09:06AM 47.752 ... Looking for cached template by key "/.../
purchase_list.gtpl
05-31 09:06AM 47.754 ... LRU cache hit! Hit #8 since Mon May 31
15:40:54 UTC 2010 ----> It works
05-31 09:06AM 47.755 ... Making template "purchase_list.gtpl"...
05-31 09:06AM 47.756 ... Creating/getting cached template...
05-31 09:06AM 47.757 ... Looking for cached template by key "/.../
includes/header.gtpl
05-31 09:06AM 47.758 ... LRU cache hit! Hit #9 since Mon May 31
15:40:55 UTC 2010 ----> It works
...
05-31 09:05AM 43.362 ... Creating/getting cached template...
05-31 09:05AM 43.363 ... Looking for cached template by key "/.../task/
warm_up.gtpl
05-31 09:05AM 43.364 ... LRU cache hit! Hit #238 since Mon May 31
15:39:51 UTC 2010
05-31 09:05AM 43.365 ... Making template "warm_up.gtpl"...
05-31 09:05AM 43.365 ... Template "warm_up.gtpl" request responded.
[create/get=1 ms, make=0 ms]
05-31 09:05AM 43.366 ... com.liyue.web.task.WarmUp spend : 32 ms
...
Thanks Guillaume for your kindly help and spending lots of your time,
thank you very much !!!
Tin
I think every body who uses GAE should star this issue : http://goo.gl/juDy
-->> PLEASE HELP !!
Jeff Schwartz
Hi all:
--
Vous recevez ce message, car vous êtes abonné au groupe Google Groupes Gaelyk.
Pour envoyer un message à ce groupe, adressez un e-mail à gae...@googlegroups.com.
Pour vous désabonner de ce groupe, envoyez un e-mail à l'adresse gaelyk+un...@googlegroups.com.
Pour plus d'options, consultez la page de ce groupe : http://groups.google.com/group/gaelyk?hl=fr
--
--
Jeff