| Prev | Next | Start of Chapter | End of Chapter | Contents | Glossary | Index | Comments | (3 out of 4)

Profiling Your KB's Execution

G2 can collect profile data about the executable items in your KB. Profile data show which parts of your KB executed during a particular time interval and reveal how long each part executed.

G2 collects profile data about these executable items:

The profile data that G2 collects include three kinds of information:

Techniques for Profiling

 G2 provides various essential capabilities that support profiling, as described in this chapter. These do not in themselves constitute a profiling capability: they are the nuts and bolts from which such a capability can be constructed. If you prefer, you can write your own profiler and give it any properties and user interface you need, using the techniques described in this chapter in the G2 GUIDE User's Guide.

The G2 software includes two KBs that supply higher-level profiling capabilities:

The former is an example of a simple profiler: it can be useful for studying the essential techniques for designing profilers, and as a basis to extend and customize. The latter is a complete profiling utility: it provides sophisticated profiling capabilities, but is more difficult to extend and customize due to its greater specialization.

Both the profile.kb sample and the profiler.kb utility are self-documenting. To use either of them, merge it into the KB that you want to profile, then follow the directions in the KB to start and stop collecting profile data, and display reports of the KB's activity.

In most cases, the profiler.kb utility provides all the profiling capabilities that are needed. However, even if you do not intend to create your own profiler or extend one that is provided with G2, you should skim this chapter to gain a general understanding what a profiler does, and how and why it does it.

Understanding the Profiling Process

G2 collects profile data in memory. G2 retains profile data in memory until you direct it to clear all profile data.

You can direct G2 to start collecting profile data, to stop collecting data, and to start and stop again as many times as necessary. G2 always adds new profile data to any profile data already collected. By starting and stopping profiling more than once as your KB runs, you can measure different parts of the KB at various times without losing data.

You direct G2 to create a SYSTEM-PROFILE-INFORMATION item that contains a copy of the profile data collected so far.

Identifying Resource Requirements for Profiling

While collecting profile data does not significantly impact KB performance, profiling a large KB can consume large amounts of memory. Always have sufficient memory available for G2's use before you begin collecting profile data.

Using System Procedures for Profiling

To collect profile data about the current KB, the KB's items must call G2's profiling system procedures. Merge sys-mod.kb into your KB before you attempt to collect profile data. The KB defines these system procedures for profiling:

g2-enable-profiling
Directs G2 to start collecting profile data.
g2-disable-profiling
Directs G2 to stop collecting profile data.
g2-get-profiled-information
Creates and returns a system-profile-information item, which contains a copy of the profile data that currently resides in G2's own memory.
g2-clear-profile
Directs G2 to discard any collected profiled data that currently resides in G2's own memory.

Add actions or statements in your KB's items so that they call the procedures in a manner that supports your profiling strategy. Identifying Your Profiling Strategy offers basic recommendations.

Note: Profiling does not track activities performed by the same item from which profiling is enabled.

Collecting Profile Data

G2 starts collecting profile data when your KB invokes the g2-enable-profiling system procedure. G2 stops collecting profile data when your KB invokes the g2-disable-profiling system procedure.

The first time that your KB calls g2-enable-profiling, G2 collects a new set of profile data. If your KB calls g2-disable-profiling to stop collecting profile data, and, later in the KB's processing, calls g2-enable-profiling again, G2 adds the newest profile data to the data already collected.

Note: G2's profile data exists only as long as the G2 process itself exists. When you exit or close a G2 process, G2 discards any profile data already collected.

Changing the run-state of the current KB does not affect whether profiling is enabled. If profiling is enabled when the current KB is reset or paused, profiling remains enabled, but G2 collects no additional profiling data until the KB starts again. When the KB resumes, G2 adds any new profile data to the existing profile data.

See the G2 System Procedures Reference Manual for a complete description of the g2-enable-profiling and g2-disable-profiling system procedures.

Creating a Copy of G2's Collected Profile Data

While G2 is collecting profile data, or after G2 has stopped collecting profile data, you can direct G2 to create an item that contains a copy of the profile data collected so far. The g2-get-profiled-information system procedure creates a transient system-profile-information. You can optionally transfer this system-profile-information to the workspace of your choice.

Note: You cannot add data to, or remove data from, a system-profile-information item.

See the G2 System Procedures Reference Manual for a complete description of the g2-get-profiled-information system procedure.

Identifying the Contents of a System-Profile-Information

Each call to the g2-get-profile-information system procedure creates a new system-profile-information. The definition for the SYSTEM-PROFILE-INFORMATION class is stored in sys-mod.kb.

Each system-profile-information contains three kinds of information:

Use a system-profile-information's data to analyze how well your KB uses the CPU timeslice that your computer gave to your G2 process during profiling. In other words, a system-profile-information's data shows how efficiently G2 spends its time performing your KB's work relative to other tasks maintained by the G2 task scheduler.

A system-profile-information's data does not show the sum of the CPU timeslices within which your G2 process executed during the profiling period. Therefore, you cannot use the data from a system-profile-information to evaluate how efficiently G2 uses your computer's resources in relation to the computer's other activities. Such an analysis requires platform-specific techniques to monitor operating-system processes.

The following table summarizes the attributes specific to the SYSTEM-PROFILE-INFORMATION class.

Attribute Purpose of Attribute
Total-profiled-time
The interval of real time that passed during profiling
Idle-time
G2 clock time spent not performing activities that are managed by the G2 task scheduler
Clock-tick-time
G2 clock time spent servicing the G2 clock
Icp-time
G2 clock time spent on ICP data transfer and other network-related tasks, such as performing or checking for G2-to-G2 communication, G2 foreign functions, or remote procedure calls
Workstation-time
G2 clock time spent receiving user input and setting up G2 output to the workstation
Display-time
G2 clock time spent rendering information on the workstation's display
Scheduling-time
G2 clock time spent by the G2 scheduler itself
Data-service-time
G2 clock time spent performing data service tasks for the current KB
Kb-io-time
G2 clock time spent saving the current KB or writing a snapshot file
Overhead-time
G2 clock time spent on tasks managed by the scheduler, but not attributable by G2 to a particular task
Processing-time
(Derived) G2 clock time spent performing the KB's actions and statement; calculated as:
Profiled-items
An item-list whose elements are items of the ITEM-PROFILING-INFORMATION class

Understanding Relationships Among System-Profile-Information Attributes

As you attempt to make your KB perform more efficiently, you should observe the ratio of its Processing-time to its Total-profiled-time and the ratio of its Idle-time to its Total-profiled-time.

For example, in the next table, the attributes of profile-data indicate that, during this particular profiling period, G2 spent more of its time waiting for user-defined processing to execute than performing that processing.


The ratio of Processing-time to Total-profiled-time ( 0.257 / 5.982 = 0.04, or 4%) is much smaller than the ratio of Idle-time to Total-profiled-time ( 5.528 / 5.982 = 0.92, or 92%).

Representing Empty Profile Data

If your KB has not called g2-enable-profiling since your G2 process started, or since your KB most recently called g2-clear-profile, and your KB calls g2-get-profiled-information, G2 creates a system-profile-information whose timing attributes are values of zero and whose Profiled-items item-list contains zero elements.

Understanding the Processing-Time Attribute

G2 derives system-profile-information's Processing-time value from the Total-profiled-time minus the sum of the time spent performing schedulable tasks, which consists of the values in the Idle-time, Icp-time, Workstation-time, Display-time, Scheduling-time, Data-service-time, Kb-io-time, and Overhead-time attributes.

Note: G2 calculates the value of the Processing-time attribute from a real time measure, not from G2's CPU timeslice measure. Therefore, to allow g2-get-profiled-information to return a Processing-time measure that most accurately reflects your KB's actual performance within G2, you should profile your KB when G2 is the only process running, or one of very few processes running, on your computer.

Note: If you are profiling a G2 process whose process window (or connected Telewindows) displays under the control of an X Windows server process, the actual time spent during scheduled screen-drawing cannot be included in the Processing-time attribute's value.

Understanding the Profiled-Items Attribute

The Profiled-items attribute of a system-profile-information is an item-list. If G2 has collected profile data before g2-get-profiled-information was most recently called, then G2 inserts ITEM-PROFILE-INFORMATION items into this item-list. Each item-profile-information contains profile data about each executable item that was invoked during profiling.

The definition for the ITEM-PROFILE-INFORMATION class is stored in sys-mod.kb. The following table summarizes the attributes specific to the ITEM-PROFILE-INFORMATION class.

Attribute Purpose of Attribute
Procedure-id
Item's Names attribute, or a G2-generated name
Calls
Number of times the item was invoked during profiling
Total-time
Total G2 clock time spent executing this item during profiling
Time-per-call
(Derived) Average G2 clock time spent per invocation of the item; calculated as:
Profiled-activities
An item-list of ACTIVITY-PROFILE-INFORMATION items

For each item-profile-information inserted in the Profiled-items attribute's item-list, G2 automatically concludes an instance of a profiled-by relation between the item-profile-information and the item it references. Find the profiled-by relation definition in the Profiling Procedures workspace in the sys-mod.kb file.

Tip: Use the profiled-by relations in conjunction with the g2-name-for-item system procedure to assign G2-generated names to unnamed items that were invoked during profiling.

Understanding the Profiled-Activities Attribute

The Profiled-activities attribute of an item-profile-information is an item-list. For each action or statement that G2 performed within an invoked item during profiling, G2 creates an ACTIVITY-PROFILE-INFORMATION item and inserts it into this item-list.

The definition for the ACTIVITY-PROFILE-INFORMATION class is stored in the Profiling Procedures workspace in sys-mod.kb. The following table summarizes the attributes specific to the ACTIVITY-PROFILE-INFORMATION class.

Attribute Purpose of Attribute
Activity-name
Name of a G2 executable activity (See the table Actions and Statements that G2 Profiles below.)
Activity-count
Number of times this activity executed for this item during profiling

The following table lists the activities in an invocable item for which G2 collects profile data. Each activity represents either an action or a statement.

Actions and Statements that G2 Profiles
Activity Name (as reported) Description
abort action
Abort a procedure or procedure invocation
activate action
Activate an activatable subworkspace
allow other processing statement
allow other processing statement
assign local variable statement
Assignment to a local name
begin rule actions
Invoke a rule
call next method statement
Call another procedure
call statement
Call another procedure
case statement
case ... of statement
change action
All change actions other than change color attribute/color pattern, change the text of, and change element in list or array
change array or list element action
change element in list or array
change color action
Change color attribute or color pattern of an item
change text action
Change value of a text attribute
collect data statement
collect data statement
conclude action
Assign value to a table attribute
conclude has no current value action
Force a variable's value to be expired
conclude has no value action
Assign value to a table attribute
conclude not related action
Remove a relation instance between two items
conclude relation action
Create a relation instance between two items
create action
Create a transient item (not a connection)
create by cloning action
Create a transient item (not a connection) by cloning
create connection action
Create a transient connection
deactivate action
Deactivate an activatable subworkspace
delete action
Delete a transient item
do in parallel statement
do in parallel statement
do in parallel until one completes statement
do in parallel until one completes statement
exit if statement
exit if statement
focus action
Invoke rules of specific focal class
for in parallel statement
Parallel iteration
for in parallel until one completes statement
Parallel iteration with race condition
for statement
for statement
halt action
G2 stops running the current KB
hide action
Hide a workspace
if-then statement
if ... then statement
if-then-else statement
if ... then ... else statement
inform action
Place a message on the specified workspace
insert action
Add an element to a g2-list
invoke action
Invoke a rule
make permanent action
Make an item permanent
make subworkspace action
Create a subworkspace of an item
make transient action
Make a item transient
move action
Change position of an item's icon within a workspace
on error statement
on error statement
pause kb action
Change the run-state of the current KB to paused
print action
Print a workspace
remove action
Remove an element from a g2-list
repeat statement
repeat statement
reset kb action
Change the run-state of the current KB to initial/reset
return statement
return statement
rotate action
Rotate an item's icon on a workspace
set action
Assign a value to a GSI variable or a simulation variable. The G2 Simulator, which can use simulation variables, is a superseded capability. For more information, see Appendix F, Superseded Practices.
show action
Display a workspace
shut down G2 action
Shut down G2
signal error statement
signal statement
start action
Invoke a G2 procedure
start rpc action
Invoke a remote procedure
system call statement
Call an internal G2 operation or procedure
transfer action
Transfer an item to a workspace
update action
Update a display item or variable
wait for interval statement
wait for interval statement
wait until event statement
wait until statement with event predicate
wait until statement
wait until statement

Profiling Executable Items and Activities

G2 profiles executable items starting with the first operation executed in the item and ending with the first operation executed in the next executable item that the KB's processing invokes, or ending with the first operation in the next distinct G2 task that is invoked.

Because individual G2 activities are fine-grained, G2 does not collect timing data on each activity invocation. Rather, when profiling, G2 collects only the number of times each activity is invoked within a given executable item.

Resetting G2's Profile Data

In some situations, you might prefer to clear G2's existing profile data before collecting more profile data. To clear all profile data from G2, invoke the g2-clear-profile system procedure.

After your KB has invoked g2-enable-profiling once, G2 retains a set of profile data in memory until g2-clear-profile is invoked.

See the G2 System Procedures Reference Manual for a complete description of the g2-clear-profile system procedure.

Identifying Your Profiling Strategy

Typically, you collect profile data for some length of time that is significant for testing purposes. You can begin by collecting profile data for all executable items in your KB. For example, to do so, you could include an initially rule in your KB that invokes g2-enable-profiling.

You must code your own actions or statements in your KB that call these system procedures, as follows:

For example, code the actions or statements in your KB's items so that they call the profiling system procedures in this order:

  1. Call g2-enable-profiling to begin collecting profile data.

  2. Call g2-disable-profiling to stop collecting profile data.

  3. Whether automatically or manually, invoke the item that calls g2-get-profiled-information.

  4. After calling g2-clear-profile or not, repeat Steps 1 through 3 to capture and report on your KB's processing again under different circumstances.

  5. Whether automatically or manually, invoke the item that calls your own reporting procedure for the profile data contained in a particular system-profile-information item.

Reporting the Contents of a System-Profile-Information

You can code your own procedure that reports the contents of a system-profile-information. Use the procedure code in the figure entitled Sample Procedure that Demonstrates Profiling System Procedures as a foundation for your report procedure.

Hint: Some items that are profiled might not have a name. As shown in the sample procedure that follows, you can use the g2-name-for-item system procedure to assign a generated name to any unnamed profiled item. See the G2 System Procedures Reference Manual for a full description of g2-name-for-item.

Sample Procedure that Demonstrates Profiling System Procedures


Sample Procedure that Demonstrates Profiling (continued)


Analyzing Profiling Data

Collecting and analyzing profile data are the first steps in evaluating your KB's performance. With this information, you can use several techniques to improve your KB's efficiency of execution:

| Prev | Next | Start of Chapter | End of Chapter | Contents | Glossary | Index | Comments | (3 out of 4)

Copyright © 1997 Gensym Corporation, Inc.