%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
%%
%W  debug.msk                 GAP manual                    Thomas Breuer
%W                                                       Alexander Hulpke
%W                                                       Martin Schoenert
%%
%H  @(#)$Id: debug.msk,v 1.25.2.1 2006/03/07 22:06:33 jjm Exp $
%%

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Chapter{Debugging and Profiling Facilities}

This chapter describes some functions that are useful mainly for
debugging and profiling purposes.

The sections~"ApplicableMethod" and~"Tracing Methods" show how to get
information about the methods chosen by the method selection mechanism
(see chapter~"prg:Method Selection" in the programmer's manual).

The final sections describe functions for collecting statistics about
computations (see "Runtime", "Profiling").


%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Recovery from NoMethodFound-Errors}

When the method selection fails because there is no applicable method, an
error as in the following example occurs and a break loop is entered:

%notest
\beginexample
gap> IsNormal(2,2);
Error, no method found! For debugging hints type ?Recovery from NoMethodFound
Error, no 1st choice method found for `IsNormal' on 2 arguments called from
<function>( <arguments> ) called from read-eval-loop
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you can 'return;' to continue
brk> 
\endexample

This only says, that the method selection tried to find a method for 
`IsNormal' on two arguments and failed. In this situation it is
crucial to find out, why this happened. Therefore there are a few functions
which can display further information.
Note that you can leave the break loop by the `quit' command (see~"quit")
and that the information about the incident is no longer accessible
afterwards.

%If you use `return' you have to supply a method
%which matches.

\Declaration{ShowArguments}
\Declaration{ShowArgument}
\Declaration{ShowDetails}
\Declaration{ShowMethods}
\Declaration{ShowOtherMethods}


%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{ApplicableMethod}\nolabel

\Declaration{ApplicableMethod}

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Tracing Methods}

\Declaration{TraceMethods}
\Declaration{UntraceMethods}

\beginexample
gap> TraceMethods( [ Size ] );
gap> g:= Group( (1,2,3), (1,2) );;
gap> Size( g );
#I  Size: for a permutation group
#I  Setter(Size): system setter
#I  Size: system getter
#I  Size: system getter
6
gap> UntraceMethods( [ Size ] );
\endexample

\Declaration{TraceImmediateMethods}

\beginexample
gap> TraceImmediateMethods( true );
gap> g:= Group( (1,2,3), (1,2) );;
#I  immediate: Size
#I  immediate: IsCyclic
#I  immediate: IsCommutative
#I  immediate: IsTrivial
gap> Size( g );
#I  immediate: IsNonTrivial
#I  immediate: Size
#I  immediate: IsNonTrivial
#I  immediate: GeneralizedPcgs
#I  immediate: IsPerfectGroup
#I  immediate: IsEmpty
6
gap> TraceImmediateMethods( false );
gap> UntraceMethods( [ Size ] );
\endexample

This example gives an explanation for the two calls of the
``system getter'' for `Size'.
Namely, there are immediate methods that access the known size
of the group.
Note that the group `g' was known to be finitely generated already
before the size was computed,
the calls of the immediate method for `IsFinitelyGeneratedGroup'
after the call of `Size' have other arguments than `g'.


%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Info Functions}

The `Info' mechanism permits operations to display intermediate results or
information about the progress of the algorithms.
Information is always given according to one or more *info classes*. Each of the
info classes defined in the {\GAP} library usually covers a certain range
of algorithms, so for example `InfoLattice' covers all the cyclic extension
algorithms for the computation of a subgroup lattice.

The amount of information to be displayed can be specified by the user for
each info class separately by a *level*, the higher the level the more
information will be displayed.
Ab initio all info classes have level zero except `InfoWarning' 
(see~"InfoWarning") which initially has level 1.

\>NewInfoClass( <name> ) O

creates a new info class with name <name>.

\>DeclareInfoClass( <name> ) F

creates a new info class with name <name> and binds it to the global
variable <name>. The variable must previously be writable, and is made 
readonly by this function.

\>SetInfoLevel( <infoclass>, <level> ) O

Sets the info level for <infoclass> to <level>.

\>InfoLevel( <infoclass> ) O

returns the info level of <infoclass>.

\>Info( <infoclass>, <level>, <info> [,<moreinfo> . . .] )

If the info level of <infoclass> is at least <level> the remaining
arguments (<info> and possibly <moreinfo> and so on) are evaluated and
viewed, preceded by '\#I  ' and followed by a newline. Otherwise the
third and subsequent arguments are not evaluated. (The latter can save
substantial time when displaying difficult results.)

\beginexample
gap> InfoExample:=NewInfoClass("InfoExample");;
gap> Info(InfoExample,1,"one");Info(InfoExample,2,"two");
gap> SetInfoLevel(InfoExample,1);
gap> Info(InfoExample,1,"one");Info(InfoExample,2,"two");
#I  one
gap> SetInfoLevel(InfoExample,2);
gap> Info(InfoExample,1,"one");Info(InfoExample,2,"two");
#I  one
#I  two
gap> InfoLevel(InfoExample);
2
gap> Info(InfoExample,3,Length(Combinations([1..9999])));
\endexample

Note that the last `Info' call is executed without problems,
since the actual level `2' of `InfoExample' causes `Info' to ignore
the last argument, which prevents `Length(Combinations([1..9999]))'
from being evaluated;
note that an evaluation would be impossible due to memory restrictions.


A set of info classes (called an *info selector*) may be passed to a
single `Info' statement. As a shorthand, info classes and selectors
may be combined with `+' rather than `Union'. In this case, the
message is triggered if the level of *any* of the classes is high enough.

\beginexample
gap> InfoExample:=NewInfoClass("InfoExample");;
gap> SetInfoLevel(InfoExample,0);
gap> Info(InfoExample + InfoWarning, 1, "hello");
#I  hello
gap> Info(InfoExample + InfoWarning, 2, "hello");
gap> SetInfoLevel(InfoExample,2);
gap> Info(InfoExample + InfoWarning, 2, "hello");
#I  hello
gap> InfoLevel(InfoWarning);
1
\endexample

\>`InfoWarning' V

is an info class to which general warnings are sent at level 1, which is
its default level. More specialised warnings are `Info'-ed at `InfoWarning'
level 2, e.g.~information about the autoloading of {\GAP} packages and the
initial line matched when displaying an on-line help topic.

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Assertions}

Assertions are used to find errors in algorithms.
They test whether intermediate results conform to required conditions
and issue an error if not.

\>SetAssertionLevel( <lev> ) F

assigns the global assertion level to <lev>. By default it is zero.

\>AssertionLevel() F

returns the current assertion level.

\>Assert( <lev>, <cond> ) F
\>Assert( <lev>, <cond>, <message> ) F

With two arguments, if the global assertion  level  is  at  least  <lev>,
condition <cond> is tested and if it does not return `true' an  error  is
raised.
Thus `Assert(lev, <cond>)' is equivalent to the code
\begintt
if AssertionLevel() >= lev and not <cond> then
  Error("Assertion failure");
fi;
\endtt

With the <message> argument form of the `Assert' statement, if the global
assertion level is at least <lev>, condition <cond> is tested and  if  it
does not return `true' then <message> is evaluated and printed.

Assertions are used at various places in the library.
Thus turning assertions on can slow code execution significantly.

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Timing}

\>Runtimes() F

`Runtimes' returns a record with components bound to integers or `fail'. 
Each integer
is the cpu time (processor time) in milliseconds spent by {\GAP} in a
certain status:

\beginlist
\item{}`user\_time'\ \  cpu time spent with {\GAP} functions (without child 
processes).
\item{}`system\_time'\ \  cpu time spent in system calls, e.g., file access 
(`fail' if not available).
\item{}`user\_time\_children'\ \  cpu time spent in child processes (`fail' if not available).
\item{}`system\_time\_children'\ \  cpu time spent in system calls by child
processes (`fail' if not available).
\endlist

Note that this function is not fully supported on all systems. Only the
`user\_time' component is (and may on some systems include the system
time). 

The following example demonstrates tasks which contribute to the different
time components:

\begintt
gap> Runtimes(); # after startup
rec( user_time := 3980, system_time := 60, user_time_children := 0, 
  system_time_children := 0 )
gap> Exec("cat /usr/bin/*||wc"); # child process with a lot of file access
 893799 7551659 200928302
gap> Runtimes();
rec( user_time := 3990, system_time := 60, user_time_children := 1590, 
  system_time_children := 600 )
gap> a:=0;;for i in [1..100000000] do a:=a+1; od; # GAP user time
gap> Runtimes();  
rec( user_time := 12980, system_time := 70, user_time_children := 1590, 
  system_time_children := 600 )
gap> ?blabla  # first call of help, a lot of file access
Help: no matching entry found
gap> Runtimes();
rec( user_time := 13500, system_time := 440, user_time_children := 1590, 
  system_time_children := 600 )
\endtt

\>Runtime() F

`Runtime' returns the time spent by {\GAP} in milliseconds as an integer.
It is the same as the value of the `user\_time' component given by `Runtimes',
as explained above.

See `StringTime' ("StringTime") for a translation from milliseconds into
hour/minute format.

\>`time;'{time}@{`time'}

in the read-eval-print loop returns the time the last command took.

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Profiling}

Profiling of code can be used to determine in which parts of a program how
much time has been spent during runtime.

\Declaration{ProfileOperations}
\Declaration{ProfileOperationsAndMethods}
\Declaration{ProfileMethods}
\Declaration{UnprofileMethods}
\Declaration{ProfileFunctions}
\Declaration{UnprofileFunctions}
\Declaration{ProfileGlobalFunctions}

\Declaration{DisplayProfile}
\Declaration{PROFILETHRESHOLD}

\Declaration{ClearProfile}

%notest
\beginexample
gap> ProfileOperationsAndMethods(true);
gap> ConjugacyClasses(PrimitiveGroup(24,1));;
gap> ProfileOperationsAndMethods(false);
gap> DisplayProfile();
  count  self/ms  chld/ms  function                                           
[the following is excerpted from a much longer list]
   1620      170       90  CycleStructurePerm: default method                 
   1620       20      260  CycleStructurePerm                                 
 114658      280        0  Size: for a list that is a collection              
    287       20      290  Meth(CyclesOp)                                     
    287        0      310  CyclesOp                                           
     26        0      330  Size: for a conjugacy class                        
   2219       50      380  Size                                               
      2        0      670  IsSubset: for two collections (loop over the ele*  
     32        0      670  IsSubset                                           
     48       10      670  IN: for a permutation, and a permutation group     
      2       20      730  Meth(ClosureGroup)                                 
      2        0      750  ClosureGroup                                       
      1        0      780  DerivedSubgroup                                    
      1        0      780  Meth(DerivedSubgroup)                              
      4        0      810  Meth(StabChainMutable)                             
     29        0      810  StabChainOp                                        
      3      700      110  Meth(StabChainOp)                                  
      1        0      820  Meth(IsSimpleGroup)                                
      1        0      820  Meth(IsSimple)                                     
    552       10      830  Meth(StabChainImmutable)                           
     26      490      480  CentralizerOp: perm group,elm                      
     26        0      970  Meth(StabilizerOfExternalSet)                      
    107        0      970  CentralizerOp                                      
    926       10      970  Meth(CentralizerOp)                                
    819     2100     2340  Meth(IN)                                           
      1       10     4890  ConjugacyClasses: by random search                 
      1        0     5720  ConjugacyClasses: perm group                       
      2        0     5740  ConjugacyClasses                                   
            6920           TOTAL                                              
gap> DisplayProfile(StabChainOp,DerivedSubgroup); # only two functions
  count  self/ms  chld/ms  function                                           
      1        0      780  DerivedSubgroup                                    
     29        0      810  StabChainOp                                        
            6920           OTHER                                              
            6920           TOTAL                                              
\endexample

Note that profiling (even the command `ProfileOperationsAndMethods(true)')
can take substantial time and {\GAP} will perform much more slowly
when profiling than when not.

\Declaration{DisplayCacheStats}
\Declaration{ClearCacheStats}

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Information about the version used}

\Declaration{DisplayRevision}


%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Test Files}

Test files are used to check that {\GAP} produces correct results in
certain computations. A selection of test files for the library can be
found in the `tst' directory of the {\GAP} distribution.

\>ReadTest( <name-file> ) O

reads a test file.
A test file starts with a line

\begintt
gap> START_TEST("arbitrary identifier string");
\endtt

(Note that the `gap>' prompt is part of the line!)
It continues by lines of {\GAP} input and corresponding output.
The input lines again start with the `gap>' prompt (or the `>' prompt if
commands exceed one line). The output is exactly as would result from typing
in the input interactively to a {\GAP} session
(on a screen with 80 characters per line).

The test file stops with a line

\begintt
gap> STOP_TEST( "filename", 10000 );
\endtt

Here the string `"filename"' should give the name of the test file. The
number is a proportionality factor that is used to output a ``{\GAP}stone''
speed ranking after the file has been completely processed. For the files
provided with the distribution this scaling is roughly equalized to yield
the same numbers as produced by `combinat.tst'.

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Debugging Recursion}

The {\GAP} interpreter monitors the level of nesting of {\GAP}
functions during execution. By default, whenever this nesting reaches
a multiple of 5000, {\GAP} enters a break loop ("break loops") allowing 
you to terminate the calculation, or enter `return;' to continue it. 


%notest
\beginexample
gap> dive:= function(depth) if depth>1 then dive(depth-1); fi; return; end;
function( depth ) ... end
gap> dive(100);
gap> OnBreak:= function() Where(1); end; # shorter traceback
function(  ) ... end
gap> dive(6000);
recursion depth trap (5000)
 at
dive( depth - 1 );
 called from
dive( depth - 1 ); called from
...
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you may 'return;' to continue
brk> return;
gap> dive(11000);
recursion depth trap (5000)
 at
dive( depth - 1 );
 called from
dive( depth - 1 ); called from
...
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you may 'return;' to continue
brk> return;
recursion depth trap (10000)
 at
dive( depth - 1 );
 called from
dive( depth - 1 ); called from
...
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you may 'return;' to continue
brk> return;
gap> 
\endexample

This behaviour can be controlled using the procedure

\> SetRecursionTrapInterval( <interval> ) F

<interval> must be a non-negative small integer (between 0 and
$2^{28}$). An <interval> of 0 suppresses the monitoring of recursion
altogether. In this case excessive recursion may cause {\GAP} to crash.



%notest
\beginexample
gap> dive:= function(depth) if depth>1 then dive(depth-1); fi; return; end;
function( depth ) ... end
gap> SetRecursionTrapInterval(1000);
gap> dive(2500);
recursion depth trap (1000)
 at
dive( depth - 1 );
 called from
dive( depth - 1 ); called from
...
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you may 'return;' to continue
brk> return;
recursion depth trap (2000)
 at
dive( depth - 1 );
 called from
dive( depth - 1 ); called from
...
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you may 'return;' to continue
brk> return;
gap> SetRecursionTrapInterval(-1);
SetRecursionTrapInterval( <interval> ): <interval> must be a non-negative smal\
l integer
not in any function
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you can replace <interval> via 'return <interval>;' to continue
brk> return ();
SetRecursionTrapInterval( <interval> ): <interval> must be a non-negative smal\
l integer
not in any function
Entering break read-eval-print loop ...
you can 'quit;' to quit to outer loop, or
you can replace <interval> via 'return <interval>;' to continue
brk> return 0;
gap> dive(20000);
gap> dive(2000000);
Segmentation fault
\endexample

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
\Section{Global Memory Information}

The {\GAP} environment provides automatic memory management, so that
the programmer does not need to concern themselves with allocating
space for objects, or recovering space when objects are no longer
needed. The component of the kernel which provides this is called
`GASMAN' ({\GAP} Storage MANager).  Messages reporting garbage
collections performed by GASMAN can be switched on by the `-g' command
line option (see section "command line options").  There are also some
facilities to access information from GASMAN from {\GAP} programs.

\Declaration{GasmanStatistics}

\Declaration{GasmanMessageStatus}

\Declaration{GasmanLimits}

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
%%
%E