Bookshelf v7.5: Example of Analyzing Siebel ARM Output

This topic gives one example of how to analyze Siebel ARM output. You may use Siebel ARM output differently, depending on your business model.

After running a performance aggregation analysis, the Siebel ARM post-processing tool produces the following XML output:

-<xml>
-<Group>
   <Name>SMI</Name>
      -<ResponseTime>
         <Total>325577844947</Total>
         <Average>1839422852</Average>
         <NonRecursiveCalls>177</NonRecursiveCalls>
         <RecursiveCalls>0</RecursiveCalls>
         <Max>133062957179</Max>
         <Min>3293465</Min>
      </ResponseTime>
      <ExecutionTime>
      <Parents />
      -<Children>
</Group>
-<Group>
   <Name>Database</Name>
      -<ResponseTime>
         <Total>28846037763</Total>
         <Average>2804943</Average>
         <NonRecursiveCalls>10284</NonRecursiveCalls>
         <RecursiveCalls>106</RecursiveCalls>
         <Max>3623108101</Max>
         <Min>47397</Min>
      </ResponseTime>
      +<ExecutionTime>
      +<Parents>
      +<Children>
</Group>
-<Group>
   <Name>SarmIO</Name>
      -<ResponseTime>
         <Total>756465475</Total>
         <Average>6200536</Average>
         <NonRecursiveCalls>122</NonRecursiveCalls>
         <RecursiveCalls>0</RecursiveCalls>
         <Max>181488478</Max>
         <Min>730255</Min>
      </ResponseTime>
      +<ExecutionTime>
      +<Parents>
      <Children/>
</Group>
-<Group>
   <Name>SWE</Name>
      -<ResponseTime>
         <Total>167202095979</Total>
         <Average>966486103</Average>
         <NonRecursiveCalls>173</NonRecursiveCalls>
         <RecursiveCalls>16</RecursiveCalls>
         <Max>51087996109</Max>
         <Min>141423</Min>
      </ResponseTime>
      -<ExecutionTime>
      -<Parents>
      -<Children>
</Group>
-<Group>
   <Name>Scripting Engine</Name>
      -<ResponseTime>
         <Total>42078467851</Total>
         <Average>825067997</Average>
         <NonRecursiveCalls>51</NonRecursiveCalls>
         <RecursiveCalls>0</RecursiveCalls>
         <Max>40459460508</Max>
         <Min>852767</Min>
      </ResponseTime>
      +<ExecutionTime>
      +<Parents>
      +<Children>
</Group>
-<Group>
   <Name>Workflow Engine</Name>
      -<ResponseTime>
         <Total>41809855132</Total>
         <Average>10452463783</Average>
         <NonRecursiveCalls>4</NonRecursiveCalls>
         <RecursiveCalls>14</RecursiveCalls>
         <Max>40450981149</Max>
         <Min>635413</Min>
      </ResponseTime>
      +<ExecutionTime>
      +<Parents>
      +<Children>
</Group>
</xml>

As a first step in analyzing this output, review the response time of each group, noting the group with the highest response time. The results of this review appear in Table 12.

Table 12. Response Times Per Group
Group	Response Time (Nanoseconds)	Response Time (Seconds)
Server Thread (SMI)	325,577,844,947	325
Database	28,846,037,763	28
SARM I/O	756,465,475	.75
SWE	167,202,095,979	167
Scripting Engine	42,078,467,851	42
Workflow Engine	41,809,855,132	41

The Server Thread (SMI) group had the largest response time. Reviewing the SMI group in further detail reveals:

Therefore, the Server Thread (SMI) request that took much longer than the average (133 seconds) could indicate an area for performance improvement. To investigate further, expand the Server Thread (SMI) group, which produces the following output:

-<xml>
-<Group>
   <Name>SMI</Name>
      -<ResponseTime>
      +<ExecutionTime>
      <Parents />
      -<Children>
      -<ChildGroup>
         <Name>Database</Name>
         <TotalContributedTime>10052385093</TotalContributedTime>
         <Calls>7378</Calls>
         <Average>1362481</Average>
         <PercentageTime>5.65</PercentageTime>
         <PercentageCalls>96.62</PercentageCalls>
      </ChildGroup>
      -<ChildGroup>
         <Name>SarmIO</Name>
         <TotalContributedTime>695242267</TotalContributedTime>
         <Calls>85</Calls>
         <Average>8179320</Average>
         <PercentageTime>0.39</PercentageTime>
         <PercentageCalls>1.11</PercentageCalls>
      </ChildGroup>
      -<ChildGroup>
         <Name>SWE</Name>
         <TotalContributedTime>167202095979</TotalContributedTime>
         <Calls>173</Calls>
         <Average>966486103</Average>
         <PercentageTime>93.96</PercentageTime>
         <PercentageCalls>2.27</PercentageCalls>
         </ChildGroup>
      </Children>
</Group>
+<Group>
+<Group>
</xml>

The SWE area's contribution time was the highest with 167 seconds, against 10 seconds for the Database area and .6 seconds for the SarmIO area.

The total number of calls spent on the children groups is only 2.27% (173 / (7378+85+173)) of the calls (PercentageCalls) were made to SWE. However, those 2.27% accounted for 93.96% (167202095979 / (10052385093 + 695242267+ 167202095979)) of the execution time (PercentageTime) within the children groups.

Although there are very few calls within the SWE child group, the percent of time (93.96%) spent on those SWE calls was very high. With this information, a further review of the SWE area is necessary.

After further review and isolation, this output file indicated the SWE and scripting engine areas experienced higher response times. These areas indicate that some of the application views may be too complex. For further analysis and to refine the source of longer response times: