[GAP Forum] Mystry call to Order

[Alexander Hulpke]

Dear Armando Mandel, Dear Forum,

> fter struggling with a very slow running function, I was met with a
> mystery.  Here is profiling data:

>
>  94236  1322830       80  Order: for a group
>         1325010           TOTAL
>
> As you can see, Order takes up all the time. However, Complete does
> not involve any group.

This is a known problem in the profiling code. The call in question is  
`Size'.
  what is happening, however, is that there is a method installation  
for `Order'  for groups (in lib/grp.gi) for which the method is simply  
the operation `Size'. This means, that the function `Size' internally  
gets labeled as a *method*  for the operation `Order' for groups.
unfortunately this is not easily fixed: doing so would require an  
extra indirection when calling methods, which are operations  
themselves. This would slow things down a little bit. In view of this,  
I would argue that the mislabeling of the profile is the lesser evil.

While this was not asked, I would like to make another remark about  
profiling, which might have an impact on your analysis, as you seem to  
be doing just basic list operations for which all function calls  
should be quick:
Turning on profiling slows the system down. This is happening, because  
there is a (constant!) extra cost with every function call. This extra  
cost is accounted as part of the runtime for this function when  
displaying the profile. For functions, which are called very often,  
but themselves are very fast (such as many list operations) this is  
skewing the result to the point of making it unusable. (This is the  
price one has to pay for using an interpreted language with profiling  
being built into the interpreter.)
Seeing the list of functions which are called, I fear that your code  
might be in this situation.

To find out cold bottlenecks in similar situations, I have resort to   
using the function `Runtime()'  (which returns the milliseconds since  
the start of GAP) to basically do profiling by hand. (I.e.  I set at  
the start and end of each function (or functionality block within a  
function)
total_time_this_function:=Runtime()-total_time_this_function;
  as a result, time for this function is summed up in  the variable  
`total_time_this_function'.

Doing so lets me decide on the granularity of profiling and avoids  
function calls skewing the results. Admittedly it will never win a  
prize for elegance.

All the best,
Alexander Hulpke
>

-- Colorado State University, Department of Mathematics,
Weber Building, 1874 Campus Delivery, Fort Collins, CO 80523-1874, USA
email: hulpke at math.colostate.edu, Phone: ++1-970-4914288
http://www.math.colostate.edu/~hulpke