Profiling Stages

When testing stages, you may want to see how efficient the plug-ins you're using are, and where most of the processing time is being used. You can meter any session using a property, _ProfileStage, to break down processing time by plug-in.

 

You set the value of the _ProfileStage property to Y and then add it to the <inputs> section of the AutoSDK file for the service you want to profile. Each pipeline stage will then run in a special profile mode for that session.

 

It will execute each plug-in 100 times each on the same session, time this, then print out the percentage of time spent within each plug-in.

 

For example, adding <_ProfileStage>Y</_ProfileStage> as an input to the confconn.xml AutoSDK file, the pipeline logs the following information (the most time consuming plug-ins are in shown in bold):

 

12/29/99 18:13:44 [audioconfconn][INFO] Total execution time: 4046343 counts
12/29/99 18:13:44 [audioconfconn][INFO] Relative execution times:

12/29/99 18:13:44 [audioconfconn][INFO] mtiintl: 0.835396% (33803 counts)

12/29/99 18:13:44 [audioconfconn][INFO] mti: 0.840042% (33991 counts)

12/29/99 18:13:44 [audioconfconn][INFO] Precision: 1.229233% (49739 counts)

12/29/99 18:13:44 [audioconfconn][INFO] DiscountCalculator: 25.425081% (1028786 counts)

12/29/99 18:13:44 [audioconfconn][INFO] ConnTaxCalc: 0.973991% (39411 counts)

12/29/99 18:13:44 [audioconfconn][INFO] ServiceLevel: 1.911084% (77329 counts)

12/29/99 18:13:44 [audioconfconn][INFO] mincost: 1.043115% (42208 counts)

12/29/99 18:13:44 [audioconfconn][INFO] Account: 19.051845% (770903 counts)

12/29/99 18:13:44 [audioconfconn][INFO] namespace: 1.328830% (53769 counts)

12/29/99 18:13:44 [audioconfconn][INFO] ServiceLevelDefault: 5.355848% (216716 counts)

12/29/99 18:13:44 [audioconfconn][INFO] TotalConfConn: 1.088019% (44025 counts)

12/29/99 18:13:44 [audioconfconn][INFO] viewproduct: 1.789097% (72393 counts)

12/29/99 18:13:44 [audioconfconn][INFO] confconnvbhook: 14.308080% (578954 counts)

12/29/99 18:13:44 [audioconfconn][INFO] failure: 0.918756% (37176 counts)

12/29/99 18:13:44 [audioconfconn][INFO] TaxationRounding: 0.946880% (38314 counts)

12/29/99 18:13:44 [audioconfconn][INFO] ModifyStartTime: 0.849533% (34375 counts)

12/29/99 18:13:44 [audioconfconn][INFO] weightedconn: 7.004621% (283431 counts)

12/29/99 18:13:44 [audioconfconn][INFO] weightedintl: 4.688826% (189726 counts)

12/29/99 18:13:44 [audioconfconn][INFO] duration: 0.846962% (34271 counts)

12/29/99 18:13:44 [audioconfconn][INFO] PhoneCrack: 9.564760% (387023 counts)