Re: WO and Memory Management
Re: WO and Memory Management
- Subject: Re: WO and Memory Management
- From: Owen McKerrow <email@hidden>
- Date: Fri, 14 Jul 2006 15:11:49 +1000
Hi Chuck
Again see comments below.....
Hi All,
We are setting up an application of ours on a clients server,
they did some stress testing to see if they needed a bigger box
and discovered something strange.
Their comments ....
The webobjects versions have been stress tested further, we are
getting ok
results but far worse then I was hoping. RIS Public faired
worse the RIS
with it starting to get error with only 5 simultaneous users
making simple
request 5 seconds apart (running with 2 instances each with -
mx512M.
That is odd. Are you dispatching requests concurrently?
No, getting them to retest with it on.
That should make a considerable difference, unless the app is doing
a lot of EOF activity.
A major point of interest is that garbage collection does not
appear to be
active for these instances.
Check for I/O and DB usage. How long does the average request
take to process?
From the stats page :
Transactions 691
Active Session 0
Average transactions 5.031
Averegae idle 131.627
Five seconds on average is, IMHO, way too long.
Mine 2 :)
Either all of your actions are a little slow or some are very
slow. Sight unseen, my money is on the latter. Usually this is
the result of DB access,
either queries that are slow to evaluate due to missing indexes
DOH ! **Hits self in the head** Thats one thing I need to do when
there DBA gets back from holidays :) We moved the DB from OpenBase to
Oracle and we haven't been back an applied indexing yet : )
or lots of single row queries due to a lack of batch faulting and
pre-fetching in the application.
I have fiddled with it today. At the beginning of the day it looked
like (Note this a request for a page that loads a displaygroup to
display every publication I have in the DB and the stats before are
for the first time it is accessed for the app ) :
09:45:42,150 DEBUG [WorkerThread0] (PublicationsList:48 <init>) -
Publication Constructor
09:45:43,188 DEBUG [WorkerThread0] (PublicationsList:149
updatePublicationListing) - Update Pubs
09:45:45,001 DEBUG [WorkerThread0] (PublicationsList:208
updatePublicationListing) - End Update Pubs.762 total Pubs
09:45:48,257 OFF [WorkerThread0] (Log.NSLogOut:1546 appendln) - Now
asleep
After my tweaks ( the biggest time saver here was changing to use
EOSharedEditingContext, as its a read only ap ) :
13:32:53,295 DEBUG [WorkerThread0] (PublicationsList:48 <init>) -
Publication Constructor
13:32:54,174 DEBUG [WorkerThread0] (PublicationsList:143
updatePublicationListing) - Update Pubs for Faculty of Education
13:32:54,920 DEBUG [WorkerThread0] (PublicationsList:196
updatePublicationListing) - End Update Pubs.762 total Pubs
13:32:58,467 OFF [WorkerThread0] (Log.NSLogOut:1546 appendln) - Now
asleep
So between the constructor ( line 1 ) and the time the Pubs have been
loaded (line 3) went from 2.8 seconds to 1.6 ( and will hopefully get
faster once I index **Hits self in the head again**)
But the biggest time is between the end of the updatePublicationsList
() and sleep(). I need to do some further testing to see if Im
grabbing more objects from the DB ( as you said "lots of single row
queries.") or its because of the actual page itself. The site has a
quotation style engine in it which basically on the fly changes the
way in which a publication is displayed. This is what suspect is
chewing up time. The other reason I think this may be the case is the
time between line 3 and line 4 doesn't change when I come back to the
page i.e. the EO's should be in memory, but the time to "render" the
page seems to be the same.
Are you a Project Wonder user?
Nope, always wonder, never plunged. It may be my pet project while Im
at WWDC this year.
Any volunteer tutors ? :)
There is a class in there that will log out all queries that take
longer than X seconds to return. That is a good way of finding
slow queries. If not, I can dig out a similar class. I thought it
was in Practical WebObjects, but I can't find it now.
If you remember where it is I would love a copy.
For lots of single queries, the best way I have found is to just
turn on SQL logging and look at what is spit out. If you see reams
of queries one after the other, each returning a single row, that
is your problem.
I will also suggest that you add this to Application or modify what
is there:
/**
* Overidden to log RR loop and gather statistics.
*/
public WOResponse dispatchRequest(WORequest request) {
NSLog.out.appendln("=========== New Request: " + request.uri
());
NSLog.out.appendln("Headers: " + request.headers());
long startTime = System.currentTimeMillis();
WOResponse response = super.dispatchRequest(request);
long endTime = System.currentTimeMillis();
NSLog.out.appendln("Elapsed Time," + (endTime -
startTime) / 1000.0 + "," + request.uri());
NSLog.out.appendln("=========== End Request: " + request.uri
());
return response;
}
That will show you the time for each request. You can turn this
into a CSV file for Excel by grepping the log
grep Elapsed AppLog.log > elapsed.csv
That lets you sort by elapsed time to find the max and min and to
graph against time.
Thanks ! That will be very handy !
We ran the tests yesterday and the started to
consume over 500M per instance (2 instance running for RIS and
RISPublic).
This morning after no activity all night the process are still
using the
full memory set. To me this is a bit of a concern, can you guys
check your
side to see if it the same there, or if there is some
configuration options
that can be put in place to improve this?
The strange thing here is that the instances don't seem to be
releasing memory. Is this normal ? Is there a setting I need to
tweak somewhere in JavaMonitor ?
This is normal for the JVM on OS X. Once the JVM has allocated
memory, it does not return it to the OS until it terminates. You
can have the instances restart more often to return this memory
to the OS. 500M seems like a lot, but that depends on what the
app is doing.
Sorry forgot to mention its on a Solaris Machine running Vs 9. WO
5.2.4 ( witha 5.3 build if it makes any difference ).
IIRC, Solaris is the same in this respect. But the last time I
deployed on Solaris was with Java 1.2 so it has been a few years. :-)
Does you app deal with a large amount of data that might explain
this memory footprint?
Yeah it does use alot of data. But as I said above I have now
switched to a shared editing context and that seems to have helped
alot ( at least on my dev machine ), ram seems to sit there at around
75 Meg.
If it does turn out that WO doesn't release its hold on said memory I
guess a staged scheduled restart across a couple of instance is a
guaranteed fix :)
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden