SortSpec + Expressions = Performance Issue

This post is about another performance issue I worked upon recently. A particular transaction (button click) was taking around 15-20 seconds to complete and I was asked to see if there is any scope of improvement and try to gain at least 5 seconds from it.

As I had mentioned when it comes to performance issue the first place where we should look is database. So, following the usual drill I fired up my dedicated client with spool enabled. I started going through spool file after executing the culprit transaction and my eyes lit up when I saw a query taking 5 seconds to complete. The usual steps somebody takes after this are

But my experience save me some time here because as soon as I saw that query had an order by clause on a custom column

ORDER BY
   T3.X_SEQ_NUM

 
I went and checked if there is an index on that column and sure enough there was no index on that column. I went ahead and created an Index in tools and applied the changes and tried once again. Just doing that saved me 4 seconds and the time taken to execute query came down to 1 second.

After a bit of prodding here and there I came to know that this table was suppose to have only 5000-10000 records that’s why nobody bothered to create an index on that column.

Lesson 1:

It doesn’t matter how many records your table is going to have, if you are applying a SortSpec make sure you have an index on that column.


Then I had a look at detailed logs and I saw that just after the query execution Siebel was opening a cursor and it took around 7-8 seconds to complete that cursor. I was able to see the following lines over and over in the detailed log file

ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 Begin: Fetch for Sql Cursor at bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 End: Fetch for Sql Cursor bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 Begin: Fetch for Sql Cursor at bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 End: Fetch for Sql Cursor bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 Begin: Fetch for Sql Cursor at bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 End: Fetch for Sql Cursor bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 Begin: Fetch for Sql Cursor at bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 End: Fetch for Sql Cursor bde1028
ObjMgrSqlCursorLog Fetch 5 000000024c813758:0 2010-09-03 07:10:24 Begin: Fetch for Sql Cursor at bde1028

 
This meant that Siebel was performing some operations on the result set returned by the query and that again was resulting in slowing down the performance. After digging down further I was able to find the particular condition that was causing this behavior. In scripting somebody has used following SearchExpr

var searchstr = “([Assign Flag] = ‘N’ AND [Status] = ‘Open’) AND (([SR Owner Id] IS NULL OR [Owner First Name]=’SIEBEL’) AND InStr([Customer Group],[Employee Group]))”;

InStr statement in this SearchExpr was forcing Siebel to get the complete result set and then run cursor over it to evaluate the condition (particularly InStr condtion). The reason to use InStr in this case was, Customer Group Field was comma separated field and we needed to see if value of Employee Group field is present in Customer Group or not. The only way to avoid this cursor was to evaluate this condition in a query rather than InStr Expr. I went ahead and changed the InStr condition to following:
 

AND [Customer Group] LIKE *[Employee Group]*

Like condition gave me the same result. This change added an additional condition in where clause but more importantly removed the cursor and saved precious 7 more seconds and overall performance improvement was about 11 seconds making the transaction to complete under 10 seconds.

Lesson 2:

If you query is going to return a large result set try to avoid calculated fields and functions in the SearchExpr or SearchSpec as it forces to Siebel to open cursors and traverse the complete record set in order to evaluate conditions causing performance issue.

5 Responses to SortSpec + Expressions = Performance Issue

  1. Hi Neel..

    Just read your post.. want to add some pointers. when you find a transaction with performance issue, you can follow the steps:
    1) get the Object manager log by increasing the log level at the server level.
    2) Identify the Long Running statements in the log.
    3) For SQL statement analysis:
    An index is useful on a particular column if the data fetched by the criteria is not more than 30 – 40%.
    So, check for indexes,individual indexes in particular for search specification criteria and consolidated index for the sort specification.
    Try to get the hot and cold time for performance SQL also.

    • With dedicated client it is easy to find the transaction and logs are generated on your local system.

      But on OM logs will be generated for all the users and on server so to find the correct logs and the actual transaction …………. well…..gud luck with that 🙂

  2. hi guys, i’m facing some pérformance issues on a claims view, the application has a lot of customizations, i created some indexes on S_INS_CLAIM table, and the SQL runs faster on Toad, but in the applicatio the view loads in about 2 min, we don’t have search specifications on the BC and the sort specification is only by created field, what can i watch?

Leave a Reply

Contribute