• Open Menu Close Menu
  • Apple
  • Shopping Bag
  • Apple
  • Mac
  • iPad
  • iPhone
  • Watch
  • TV
  • Music
  • Support
  • Search apple.com
  • Shopping Bag

Lists

Open Menu Close Menu
  • Terms and Conditions
  • Lists hosted on this site
  • Email the Postmaster
  • Tips for posting to public mailing lists
Re: logging database access time
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: logging database access time


  • Subject: Re: logging database access time
  • From: Ramsey Gurley <email@hidden>
  • Date: Tue, 17 Apr 2012 19:33:06 -0700

Oh, now those ARE handy! I didn't even know those existed :-)  Thanks for the heads up Alexis!

On Apr 17, 2012, at 1:45 PM, Alexis Tual wrote:

Also, there are Wonder properties for that :

## Enable delegate to emit SQL debugging info. The Logger used is
## log4j.category.er.extensions.ERXAdaptorChannelDelegate.sqlLogging
er.extensions.ERXAdaptorChannelDelegate.enabled=true

## How long a statement must run to cause a log message. Messages with longer than
## error also emit a stack-trace
er.extensions.ERXAdaptorChannelDelegate.trace.milliSeconds.debug=0
er.extensions.ERXAdaptorChannelDelegate.trace.milliSeconds.info=100
er.extensions.ERXAdaptorChannelDelegate.trace.milliSeconds.warn=2000
er.extensions.ERXAdaptorChannelDelegate.trace.milliSeconds.error=15000

## MaxLength of the message
er.extensions.ERXAdaptorChannelDelegate.trace.maxLength = 3000

## What entities to watch
er.extensions.ERXAdaptorChannelDelegate.trace.entityMatchPattern = .*

## Actually set the log level
log4j.logger.er.extensions.ERXAdaptorChannelDelegate.sqlLogging=debug

Alex

2012/4/18 Pascal Robert <email@hidden>
+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

 _______________________________________________
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

References: 
 >logging database access time (From: Kasper Frederiksen <email@hidden>)
 >Re: logging database access time (From: Ramsey Gurley <email@hidden>)
 >Re: logging database access time (From: Pascal Robert <email@hidden>)
 >Re: logging database access time (From: Alexis Tual <email@hidden>)

  • Prev by Date: Re: logging database access time
  • Next by Date: WOUnit
  • Previous by thread: Re: logging database access time
  • Next by thread: Re: Errors on integration branch
  • Index(es):
    • Date
    • Thread