I measure the performance with a load test using 'Paessler web stress
tool 7' and note the average time of requests over a certain period
against a set of URL's.
The pages i'm running at the moment all do a similar thing and are
built pretty much the same way but with different content come from
the database, so it's mostly repetitive work for the system.
I have enabled the trusted cache and done some tests and there is
certainly an improvement - mostly as the testing goes on and re-uses
that cache (the cache lists about 270 odd templates and has a 100% hit
ratio).
The improvement overall was around 45% (that is the average response
time was 45% better than previously), but there were still a lot of
slow requests (probably those where a template had not been cached for
it yet).
There was a reduction in the amount of file access operations (but
there are still plenty remaining).
I did find one area of code that was slowing things down a bit and
i've commented it out for now.
So below is an example of the kind of thing i'm still seeing, these
dumps taken 5 seconds apart (dumps have been thinned down by
'seestack');
Example1.
Dump1:
----------
Thread "jrpp-43":
Waiting on response from TCP peer
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:
258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0x000000016e58af60> (a
jrun.servlet.io.ReusableBufferedInputStream)
at jrun.servlet.jrpp.ProxyEndpoint.readFully(ProxyEndpoint.java:
581)
at jrun.servlet.jrpp.ProxyEndpoint.readFully(ProxyEndpoint.java:
573)
at jrun.servlet.jrpp.ProxyEndpoint.readInt(ProxyEndpoint.java:
591)
at jrun.servlet.jrpp.ProxyEndpoint.readString(ProxyEndpoint.java:
620)
at
jrun.servlet.jrpp.ProxyEndpoint.getRealPathFromServer(ProxyEndpoint.java:
540)
at jrun.servlet.jrpp.ProxyEndpoint.access$000(ProxyEndpoint.java:
36)
at jrun.servlet.jrpp.ProxyEndpoint$1.fetch(ProxyEndpoint.java:
528)
at jrunx.util.Cache.get(Cache.java:116)
at jrun.servlet.jrpp.ProxyEndpoint.getRealPath(ProxyEndpoint.java:
565)
at
jrun.servlet.WebApplicationService.getResource(WebApplicationService.java:
1028)
at
jrun.servlet.JRunServletContext.getRealPath(JRunServletContext.java:
132)
at
coldfusion.runtime.ServletContextWrapper.doGetRealPath(ServletContextWrapper.java:
166)
at
coldfusion.runtime.ServletContextWrapper._doGetRealPath(ServletContextWrapper.java:
112)
at
coldfusion.runtime.ServletContextWrapper.getRealPath(ServletContextWrapper.java:
97)
at
coldfusion.runtime.RuntimeServiceImpl.getRealPath(RuntimeServiceImpl.java:
999)
at coldfusion.filter.FusionContext.getRealPath(FusionContext.java:
758)
at coldfusion.util.Utils.expandPath(Utils.java:434)
at coldfusion.runtime.CFPage.ExpandPath(CFPage.java:3028)
at \\tur-napp1a\vol\storage_t1a\qshado1\wwwroot\shadomx\sapi
\site.cfc:424
Dump2 (5 seconds after dump1):
-----------
Thread "jrpp-43":
Waiting on response from TCP peer
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:
258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0x000000016e58af60> (a
jrun.servlet.io.ReusableBufferedInputStream)
at jrun.servlet.jrpp.ProxyEndpoint.readFully(ProxyEndpoint.java:
581)
at jrun.servlet.jrpp.ProxyEndpoint.readFully(ProxyEndpoint.java:
573)
at jrun.servlet.jrpp.ProxyEndpoint.readInt(ProxyEndpoint.java:
591)
at jrun.servlet.jrpp.ProxyEndpoint.readString(ProxyEndpoint.java:
620)
at
jrun.servlet.jrpp.ProxyEndpoint.getRealPathFromServer(ProxyEndpoint.java:
540)
at jrun.servlet.jrpp.ProxyEndpoint.access$000(ProxyEndpoint.java:
36)
at jrun.servlet.jrpp.ProxyEndpoint$1.fetch(ProxyEndpoint.java:
528)
at jrunx.util.Cache.get(Cache.java:116)
at jrun.servlet.jrpp.ProxyEndpoint.getRealPath(ProxyEndpoint.java:
565)
at
jrun.servlet.WebApplicationService.getResource(WebApplicationService.java:
1028)
at
jrun.servlet.JRunServletContext.getRealPath(JRunServletContext.java:
132)
at
coldfusion.runtime.ServletContextWrapper.doGetRealPath(ServletContextWrapper.java:
166)
at
coldfusion.runtime.ServletContextWrapper._doGetRealPath(ServletContextWrapper.java:
112)
at
coldfusion.runtime.ServletContextWrapper.getRealPath(ServletContextWrapper.java:
97)
at
coldfusion.runtime.RuntimeServiceImpl.getRealPath(RuntimeServiceImpl.java:
999)
at coldfusion.filter.FusionContext.getRealPath(FusionContext.java:
758)
at coldfusion.util.Utils.expandPath(Utils.java:434)
at coldfusion.runtime.CFPage.ExpandPath(CFPage.java:3028)
at \\tur-napp1a\vol\storage_t1a\qshado1\wwwroot\shadomx\sapi
\site.cfc:424
And again:
Example 2:
Dump1:
-----------
Thread "jrpp-54":
Waiting on response from TCP peer
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:
258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0x000000016eac7428> (a
jrun.servlet.io.ReusableBufferedInputStream)
at jrun.servlet.jrpp.ProxyEndpoint.readFully(ProxyEndpoint.java:
581)
at jrun.servlet.jrpp.ProxyEndpoint.readFully(ProxyEndpoint.java:
573)
at jrun.servlet.jrpp.ProxyEndpoint.readInt(ProxyEndpoint.java:
591)
at jrun.servlet.jrpp.ProxyEndpoint.readString(ProxyEndpoint.java:
620)
at
jrun.servlet.jrpp.ProxyEndpoint.getRealPathFromServer(ProxyEndpoint.java:
540)
at jrun.servlet.jrpp.ProxyEndpoint.access$000(ProxyEndpoint.java:
36)
at jrun.servlet.jrpp.ProxyEndpoint$1.fetch(ProxyEndpoint.java:
528)
at jrunx.util.Cache.get(Cache.java:116)
at jrun.servlet.jrpp.ProxyEndpoint.getRealPath(ProxyEndpoint.java:
565)
at
jrun.servlet.WebApplicationService.getResource(WebApplicationService.java:
1028)
at
jrun.servlet.JRunServletContext.getRealPath(JRunServletContext.java:
132)
at
coldfusion.runtime.ServletContextWrapper.doGetRealPath(ServletContextWrapper.java:
166)
at
coldfusion.runtime.ServletContextWrapper._doGetRealPath(ServletContextWrapper.java:
112)
at
coldfusion.runtime.ServletContextWrapper.getRealPath(ServletContextWrapper.java:
97)
at
coldfusion.runtime.RuntimeServiceImpl.getRealPath(RuntimeServiceImpl.java:
999)
at coldfusion.filter.FusionContext.getRealPath(FusionContext.java:
758)
at coldfusion.util.Utils.expandPath(Utils.java:434)
at coldfusion.runtime.CFPage.ExpandPath(CFPage.java:3028)
at \\tur-napp1a\vol\storage_t1a\qshado1\wwwroot\shadomx\sapi
\site.cfc:424
Dump2:
-----------
Thread "jrpp-54":
java.lang.Thread.State: RUNNABLE
at java.io.WinNTFileSystem.getBooleanAttributes(Native Method)
at java.io.File.exists(File.java:733)
at coldfusion.runtime.RuntimeServiceImpl
$1.run(RuntimeServiceImpl.java:904)
at java.security.AccessController.doPrivileged(Native Method)
at
coldfusion.runtime.RuntimeServiceImpl.checkFileExists(RuntimeServiceImpl.java:
900)
at
coldfusion.runtime.RuntimeServiceImpl.getRealPath(RuntimeServiceImpl.java:
952)
at coldfusion.filter.FusionContext.getRealPath(FusionContext.java:
758)
at coldfusion.util.Utils.expandPath(Utils.java:434)
at coldfusion.runtime.CFPage.ExpandPath(CFPage.java:3028)
at \\tur-napp1a\vol\storage_t1a\qshado1\wwwroot\shadomx\sapi
\site.cfc:424
In Example 1 above there were about three or four other threads in
this state:
Thread "jrpp-47":
java.lang.Thread.State: RUNNABLE
at java.io.WinNTFileSystem.getBooleanAttributes(Native Method)
at java.io.File.exists(File.java:733)
at coldfusion.runtime.RuntimeServiceImpl
$1.run(RuntimeServiceImpl.java:904)
at java.security.AccessController.doPrivileged(Native Method)
at
coldfusion.runtime.RuntimeServiceImpl.checkFileExists(RuntimeServiceImpl.java:
900)
at
coldfusion.runtime.RuntimeServiceImpl.getRealPath(RuntimeServiceImpl.java:
952)
at coldfusion.filter.FusionContext.getRealPath(FusionContext.java:
758)
at coldfusion.util.Utils.expandPath(Utils.java:434)
at coldfusion.runtime.CFPage.ExpandPath(CFPage.java:3028)
at \\tur-napp1a\vol\storage_t1a\qshado1\wwwroot\shadomx\sapi
\site.cfc:424
The threads in each example above had completed before the third third
dump had been taken (a further 5 seconds on).
Line 424 on that file you see is doing a if
fileExists(expandPath(<pathtofile>)) command as you can see in the
trace.
To answer your question Charlie about monitoring, yes it was just the
"start monitoring" / "stop monitoring" option being used.
And yes we will be moving one of our existing fusionreactor licences
to the server i'm testing on at the moment :)
Regards
Barry.
On May 19, 9:46 am, "charlie arehart" <charlie_li...@carehart.org>
wrote:
> Sure, but to be clear, I was answering Mr B's question in that note rather
> than yours.
> I'm guessing your note here is a reply to both notes (mine to MrB and the
> earlier one
> to you, sent about 30 minutes earlier).
>
> To your points below, it's interesting to hear now that you're saying that
> using the
> local code rather than the NAS has not made any seeming difference. I've not
> really
> regarded that to be necessarily *the issue*, but it is very interesting to
> hear that
> it's had no impact at all.
>
> I am curious about that, before we go too much further: you say "the
> performance of
> pages" is still the same" and "the thread dumps looked very similar". So how
> are you
> measuring the performance? Is it just anecdotal ("feels slow") or are you
> using some
> real measure, whether some of the stats shown in the CF Server Monitor, or
> (when you
> had FusionReactor) as what could be seen in its resource logs or System
> Overview page?
>
> I just ask because it may be interesting to confirm both that there's been no
> improvement and (possibly as useful) whether there are any particular pages
> or apps
> that are more troubled than others. I realize that may not seem likely, but
> this is a
> dilemma of looking only at thread dumps: you're only seeing what's *running
> at that
> moment*, as opposed to how things have gone in aggregate across all pages
> that did run
> (between the thread dumps). I'm just saying it could prove interesting, not
> that it
> would in your case.
>
> Moving on, rather than the NAS, I've asserted that the more interesting thing
> may be
> to see if you enabled trusted cache (since we see the stack traces showing
> the request
> doing the file system check--I pointed to some doing one method, you pointed
> to some
> doing another.) So I'm glad to hear that you will be checking that out.
>
> About that, I'll repeat, though: just turning it on may not still entirely
> solve the
> problem, if you have a problem where perhaps the template cache is not large
> enough
> for the files that are loaded, you could still have thrashing that could
> exhibit the
> same problem. Here's where the CF Server Monitor can help you. If you do
> enable
> trusted cache, and you do still see this problem occurring, then at that
> time, look in
> the CF Server Monitor at the "Template Cache Status" page (under
> Statistics>Request
> Statistics) to see what the template cache hit ratio is at that time.
>
> As for FR's "license" running out, I assume you mean the trial period ended,
> right?
> I'll tell you, since it does such a great job to allow you to do stack traces
> interactively (and tell clearly when the request ends), it may be useful for
> you to
> move a license over for this testing (since you say that you have other
> licenses).
> Your call, of course.
>
> Finally, as for the CF Server Monitor, not that it's critical, but you don't
> clarify
> which of the 3 forms of CF monitoring you turned off, but I'll assume perhaps
> it was
> "start monitoring" (it's just that you use the term "went into monitoring to
> check..[and]...it was turned on".) I'm just trying to get people to be more
> specific
> when they refer to the CF Server Monitor.
>
> Hope these or thoughts of others as they get going in their day there may
> help get you
> further. (I'm still not inclined to believe that this is somehow related to
> Windows
> itself, though I realize that was the first assertion made.) Looking forward
> to
> hearing what the resolution ultimately is.
>
> /charlie
>
>
>
> > -----Original Message-----
> > From: cfaussie@googlegroups.com [mailto:cfaus...@googlegroups.com] On
> > Behalf Of
> > BarryC
> > Sent: Tuesday, May 18, 2010 5:10 PM
> > To: cfaussie
> > Subject: [cfaussie] Re: Coldfusion 9 and Windows server 2008 64bit
>
> > Thanks for the info, though it doesn't really put me much further
> > ahead than I already was :)
>
> > Yes fusion reactor is running, and I must have indeed had the
> > coldfusion monitoring on, because when I went in to monitoring to
> > check (after was mentioned by someone yesterday), it was turned on.
> > I have since however turned off coldfusion monitoring, and at the end
> > of yesterday uninstalled fusion reactor (as the license ran out, - i
> > do have other servers with it on that I can use though).
> > I have run subsequent thread dumps and the results are still the same
> > (just without the calls to logging obviously) the performance of pages
> > is still the same.
>
> > As I mentioned previously Charlie, I had tried running my tests with a
> > local copy of files on the server (to compare the difference between
> > using the NFS and not using one), and the results were still the same
> > - the thread dumps looked very similar.
>
> > Sorry about the entire thread dump, I wasn't sure if the non running
> > jrpp threads (or other threads) would give you any info or not :).
>
> > I have indeed tried taking multiple thread dumps and comparing them, a
> > few threads can be seen running in both, but I have not found any
> > threads that ran stupidly long or any locking etc.
> > What I have noticed though in most of the thread dumps (even when the
> > same thread has been captured in two consecutive dumps) is that the
> > thread is normally at a WinNTFileSystem call e.g.
> > at java.io.WinNTFileSystem.getBooleanAttributes(Native Method)
> > at java.io.File.exists(File.java:733)
>
> > I'll try that trusted cache option you suggested Charlie.
>
> > Thanks for the help.
>
> > Regards
> > Barry.
>
> > On May 19, 5:49 am, "charlie arehart" <charlie_li...@carehart.org>
> > wrote:
> > > MrB, to your last question, I'll just add that I have often had (and
> > > worked
> > with
> > > people who had) both running (even all three, adding SeeFusion), and I've
>
> <snip>
>
> --
> You received this message because you are subscribed to the Google Groups
> "cfaussie" group.
> To post to this group, send email to cfaus...@googlegroups.com.
> To unsubscribe from this group, send email to
> cfaussie+unsubscr...@googlegroups.com.
> For more options, visit this group
> athttp://groups.google.com/group/cfaussie?hl=en.
--
You received this message because you are subscribed to the Google Groups
"cfaussie" group.
To post to this group, send email to cfaus...@googlegroups.com.
To unsubscribe from this group, send email to
cfaussie+unsubscr...@googlegroups.com.
For more options, visit this group at
http://groups.google.com/group/cfaussie?hl=en.
