Wednesday, September 12, 2007

Profiling a dynamic enumerator problem with XPRF

A recent post on the sw-gis Yahoo! Group made me think that this might be a good example to demonstrate how to use the XPRF Magik class to profile your Magik code and help you find potential bottle necks in it.

Because the post did not say so explicitly, for the purposes of this exercise I am assuming the "dynamic enumerator" referred to is the one that makes use of the methods :can_match?() and :match_string(). (Sometimes people use the term "dynamic enumerator" to refer to the core extensible enumerator functionality or the PNI "dynamic enumerator" functionality.)

The first thing I would do would be to do a profile analysis on the :match_string() method on that particular object. An analysis will tell you if you have an issue with database access or maybe some code inefficiencies in your match_string() method.

You could do that as follows...

temporarily rename your subclassed some_object_name.match_string() method to some_object_name.debug!match_string()

create a new method...

_method some_object_name.match_string(_gather args)
_global x_profile
_local ok?, result
(x_profile,ok?,result) << xprf.new_from_send(:debug!match_string|()|,_scatter args)

_return result

Then try to open the some_object_name's editor again in such a way that your match_string() code is called. Likely it will take longer now than before because all the match_string() code is being run through the XPRF profiler. When the list is populated in the editor you will be ready to investigate the performance profile.

First, make sure that the global x_profile was populated...

MagikSF> x_profile
a sw:xprf

If it is populated, you can use various interfaces to review your profile. The least user-friendly is to call x_profile.basic_report(). This will give you potentially hundreds of lines of output at the Magik prompt... a bit overwhelming if this is the first time you have done this.

Another option is to use the :xprf_dialog class. By default it is not loaded into your image, so you need to load the :profiler_magik_gui module into your current image. Use the to load the module or...

MagikSF> sw_module_manager.load_module(:profiler_magik_gui)

Once the module is loaded you can use the following Magik command to give you a more user-friendly GUI that will show you expandable lists of all the methods that were called within the context of your profiler.


Use that tool to see where the bulk of your time on the match_string() is being spent.

Possible problems you might have in your match_string() code...
- inefficient code in loops
- select predicates on non-indexed fields

Things that you could investigate to improve performance include:
- make your code more efficient
- index any columns that you are writing a predicate against.
- if the table contents are not changing very often you might consider caching the strings you get from the table in a reusable rope (eg., shared_variable) and only read the data from the table once per session in order to populate the cache

If all those things do not improve the performance to the degree that you would like, then you may want to consider using the CASE tool to configure that field as a "catalogue mapping". That will provide a different field editor but still give you the control over what goes into that field.

No comments: