Re: logging database access time
Re: logging database access time
- Subject: Re: logging database access time
- From: Pascal Robert <email@hidden>
- Date: Tue, 17 Apr 2012 13:09:05 -0400
+1. And that output can be parsed with Perl or a shell script.
> Maybe just put
>
> log4j.logger.er.transaction.adaptor.EOAdaptorDebugEnabled=DEBUG
>
> And a conversion pattern with milliseconds like
>
> log4j.appender.A1.layout.ConversionPattern=%d{HH:mm:ss.SSS} %-5p (%F:%L) - %m%n
>
> In your properties file?
>
> Ramsey
>
> On Apr 17, 2012, at 7:43 AM, Kasper Frederiksen wrote:
>
>> Hi All,
>>
>> So I am looking for bottlenecks to explain slow response times in a Web Objects server application and I have come up with the following plan for monitoring database access. I am not sure this is the best way to do it, please let me know what you think.
>>
>>
>> I extend WOApplication and in the constructor I set a new delegate to the EODatabaseContext and add an observer to NSNotificationCenter:
>> ---
>> MyDelegateAndObserver myDelegateAndObserver = ...
>> EODatabaseContext.setDefaultDelegate(myDelegateAndObserver);
>> NSNotificationCenter.defaultCenter().addObserver(
>> myDelegateAndObserver,
>> new NSSelector("hookIntoChannel", new Class[] {NSNotification.class}),
>> EODatabaseContext.DatabaseChannelNeededNotification,
>> null);
>> ---
>>
>> In the class MyDelegateAndObserver I defined "hookIntoChannel" from above and the methods to capture notifications:
>> ---
>> public void hookIntoChannel(NSNotification not){
>> final EODatabaseContext dbctxt = (EODatabaseContext)not.object();
>> final EODatabaseChannel channel = new EODatabaseChannel(dbctxt);
>> if(channel != null){
>> channel.adaptorChannel().setDelegate(this);
>> dbctxt.registerChannel(channel);
>> }
>> }
>>
>> public boolean adaptorChannelShouldEvaluateExpression(EOAdaptorChannel channel, EOSQLExpression expression){
>> /* thread safe logging: start of database round trip */
>> return true;
>> }
>>
>> public void adaptorChannelDidEvaluateExpression(EOAdaptorChannel channel, EOSQLExpression expression){
>> /* thread safe logging: end of database round trip iif expression is UPDATE or INSERT */
>> }
>>
>> public NSArray databaseContextDidFetchObjects(EODatabaseContext dbCtxt, NSArray results, EOFetchSpecification fetchSpec, EOEditingContext ec){
>> /* threadsafe logging: end of database round trip for SELECT */
>> return null;
>> }
>> ---
>>
>> I store the above logging in a java.lang.ThreadLocal and once the WO request is about to return (listen for WOApplication.ApplicationDidDispatchRequestNotification) I can sum up the number of database accesses and the total time spent waiting for database IO.
>>
>> Two thing worry me about this approach:
>> 1) I am overwriting the DatabaseContext default delegate with a custom delegate that will always answer adaptorChannelShouldEvaluateExpression=true
>> 2) What kind of overhead am I looking at here ... I suppose I will find out, but does this look like the kind of code you would include in a production environment application?
>>
>> I appreciate your input
>> -Kasper Frederiksen
>>
>>
>> ps.
>> I could not find this in the documentation so this is based on empirical evidence :). This is the life cycle of a database access as seen from the notifications sent to DatabaseContext and AdaptorChannel. I have noted where I have chosen to consider the closest points to the start/end of the database IO for the purpose of logging time spent.
>>
>> For a SQL SELECT
>> ===
>> 1) databaseContextShouldFetchObjects:
>> 2) databaseContextShouldSelectObjects:
>> 3) adaptorChannelShouldSelectAttributes:
>> 4) adaptorChannelShouldEvaluateExpression: start of database access
>> 5) adaptorChannelDidEvaluateExpression:
>> 6) adaptorChannelDidSelectAttributes:
>> 7) adaptorChannelWillFetchRow:
>> 8) adaptorChannelDidFetchRow: 7 and 8 may be repeated a number of times
>> 7) adaptorChannelWillFetchRow:
>> 9) adaptorChannelDidFinishFetching:
>> 10) databaseContextDidFetchObjects: end of database access
>>
>> For a SQL UPDATE or INSERT
>> ===
>> 1) adaptorChannelWillPerformOperations:
>> 4) adaptorChannelShouldEvaluateExpression: start of database access
>> 5) adaptorChannelDidEvaluateExpression: end of database access
>> 6) adaptorChannelDidPerformOperations:
>>
>> _______________________________________________
>> 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
>
> _______________________________________________
> 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
_______________________________________________
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