Performance Tuning Methodology

I recently had an opportunity to do a bit of performance tuning on a newly deployed production App and thought I would share a methodology for tackling some of the low hanging fruit, sort of the 80/20 rule of siebel performance tuning.  My experience is that with Siebel 7.8 and higher, on Oracle 10 and higher, most performance issues are Siebel configuration issues.  Of those, most of the issues fall into one of two categories:

• Missing Indexes
• Sort Specs

When customizing Siebel, you will frequently create new relationships between logical objects via a new foreign key.  There should always be a corresponding index for that foreign key on the M side of the 1:M or M:M  linked table.  Typically, it is just a single Id column but if for some reason, there are multiple columns (perhaps a join spec and a join constraint) make sure all of the columns from the child table are part of the index.

Be aware that all the perfectly planned indexes in the world will frequently be ignored if there is a sort spec on a query.  The sort essentially takes precedence and any index that optimizes the sort will usually be used to the exclusion of other indexes that perhaps optimize what a user is doing on that view.  I frequently see performance problems on visibility views (All/All Across) without any query refinement at all.  When this occurs, it is usually because of the All Mode Sort user property settings.  If you are seeing performance problems on an All view, try changing the settings of that property for the BC to fix the issue.

Here is a general methodology for identifying and fixing performance issues.

• For the OM component having the issue, change the Server Configuration event logging level to 4 for these events:
• SQL Parse and Execute
• Object Manager SQL Log
• Execute the operation that performs the slow query
• Open the corresponding OM log and find the SQL statement representing the slow query
• Finding the statement can be done in a couple of ways, but I use the following:
• Query for this string in the log '***** SQL Statement Execute Time'
• Look at the seconds for this line and the subsequent '***** SQL Statement Initial Fetch Time' to see a large value
• Copy the preceeding SQL statement into a SQL editor such as Toad or Benthic or whatever your fancy, swapping out the bind variables
• Run an explain plan on the statement
• Look for a line that says Table Access Full.  If you see such a line, look at the table being accessed this way and look back at the where clause to see how the SQL statement is joining to that table.  Then look in tools to see if there is an index for that table on the columns in the join to that table.
• If indexes are not an issue, but there is an Order By in the SQL statement, try commenting out the Order By and rerunning the explain plan to see how it changes.  If you see the explain plan change significantly (Cost goes down) than confirm that you really need the sort spec in the particular scenario you are in.

This is really just meant to be a way to find low hanging fruit performance issues.  It is important to configure with performance in mind (especially when using script or workflow algoritms).  Other sources of performance bottlenecks include (but are not limited to):

• Synchonous Interface round trips
• File System operations
• Network bandwidth  (especially if using a VPN)
• Memory or CPU bound servers

eScript Framework on 8.1

Converting the eScript framework to 8.1 proved a bit troublesome for me as the Siebel strong type engine has apparently dropped support for prototyping Siebel objects, such as a Business Service.  This makes the implementation a bit less clean since without being able to declare a prototype of the Log or Frame objects on application start, we are left with having to have every framework function be a child of the Application object.  This being the case, I consolidated the Frame and Log objects from the 7.8 framework into a single Utility object since there was not as much advantage in separating them.  Instead of the elegant 7.8 calls:

Log.Stack("MyMethod",1);
Log.Step("Log the time as "+Frame.Timestamp("DateTimeMilli"),3);
Log.Vars("VariableName", varValue,3)
Log.Unstack("",1);

we instead do this:

TheApplication().logStack("Write",this)
TheApplication().Utility.logStep("Log the time as "+
    TheApplication().Utility.Timestamp("DateTimeMilli"));
TheApplication().Utility.logVars("VariableName", varValue)
TheApplication().Unstack("");

Oh well.  To mitigate this somewhat, I have added a number of enhancements since the initial series of posts, which I will try to discuss sometime soon.

• Automatically tie log level to the function doing the logging (Stack/Unstack vs variables for instance), hence no need for the numeric last parameter to all logging functions (though it is still optional as an override)
• Added support for unix file systems
• Standardize the identification of logging record Ids (by passing the 'this' reference it will append the row id for methods with Write, Delete and Invoke in the name)

To implement the basic framework in 8.1, you need something like this in the Application Start event:
        this.Utility = TheApplication().GetService("ETAR Utilities");
        this.Utility.Init();

Here is the Declarations section:

var gsOutPutFileName;
var gsFileName;
var gsLogMode;
var giIndent = 2; //Indent child prop sets this many spaces to the right for each level down.
var giPSDepth = 0; // How deep in the property set tree, what level
var gaFunctionStack = new Array(); //used in debugStack function to store called functions
var giStackIndex = 0; //Where in the function stack the current function resides
var gsIndent = ''; //used in debug methods to identify stack indents
var giLogBuffer = 0;
var giLogLines = 0;
var gsLogPath = "";
var gsLogCache = "";
var gsLogSession = "";
var giErrorStack = 0;
var ge = new Object();
var gStack = new Object();
var gCurrentLogLvl;

The Utilities business service is a cached service in tools.  It's Init function looks like this:

giErrorStack = 0;
ExtendObjects();
gsLogMode = GetSysPref("Framework Log Mode");
gsLogMode = (gsLogMode == "" ? "FILE" : gsLogMode.toUpperCase());
gsLogSession = TimeStamp("DateTimeMilli");

if (TheApplication().GetProfileAttr("ETAR User Log Level") != "")
    gCurrentLogLvl = TheApplication().GetProfileAttr("ETAR User Log Level");
else gCurrentLogLvl = GetSysPref("CurrentLogLevel");
giLogBuffer = GetSysPref("Log Buffer");
gsLogPath = GetSysPref("Framework Log Path");
try {
     var os;
     os = Clib.getenv("OS");
} catch(e) { os = "UNIX Based"; }
try {
   gsFileName = "Trace-"+TheApplication().LoginName()+"-"+gsLogSession+".txt"
  //A Windows OS indicates a thick client. Assume the path is the dynamicly
  //determined Siebel_Home\Log directory, or ..\log
  if (os.substring(0, 7) == "Windows") {
//  gsLogPath = gsLogPath.replace(/\\$/, "");  //Remove trailing backslash if used
//  gsLogPath = gsLogPath.replace(/\x47/, "\\");  //switch invalid OS directory seperators
    gsLogPath = "..\\Log\\";
    gsOutPutFileName = gsLogPath+gsFileName;
  } else {
    gsLogPath = gsLogPath.replace(/\x47$/, "");  //Remove trailing backslash if used
    gsLogPath = gsLogPath.replace(/\\/, "/");  //switch invalid OS directory seperators
    gsLogPath = gsLogPath+"/";
    gsOutPutFileName = gsLogPath+gsFileName;
 }
} catch(e) {
  gsLogPath = "";
  gsOutPutFileName = gsFileName;
}