Better Tracking of Amounts of Memory Allocated and Time in the Garbage Collector

doc/ref/debug.xml

@@ -423,11 +423,14 @@ should be treated as an estimate.
 </ManSection>
 
 <ManSection>
-<Var Name="time"/>
+  <Var Name="time"/>
+  <Var Name="memory_allocated"/>
 
 <Description>
 In the read-eval-print loop,
-<Ref Var="time"/> stores the number of milliseconds the last command took.
+<Ref Var="time"/> stores the number of milliseconds the last command
+took. and <Ref Var="memory_allocated"/> stored the number of bytes of
+memory it allocated.
 </Description>
 </ManSection>
 
@@ -444,6 +447,27 @@ in nanoseconds.
 
 </Section>
 
+<!-- %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% -->
+<Section Label="Tracking Memory Usage">
+  <Heading>Tracking Memory Usage</Heading>
+
+  <ManSection>
+    <Func Name="TotalMemoryAllocated" Arg=""/>
+    <Description> <Ref Func="TotalMemoryAllocated"/> returns the total amount of memory
+    in bytes allocated by the &GAP; memory manager since &GAP; started.
+    </Description>
+  </ManSection>
+  <ManSection>
+  <Var Name="memory_allocated"/>
+
+<Description>
+In the read-eval-print loop,
+<Ref Var="memory_allocated"/> stores the number of bytes of
+memoryallocated by the last completed statement.
+</Description>
+</ManSection>
+
+</Section>
 
 <!-- %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% -->
 <Section Label="Profiling">

doc/ref/mloop.xml

@@ -27,6 +27,8 @@ interactive environment in which you use ⪆.
 <Index Key="last"><C>last</C></Index>
 <Index Key="last2"><C>last2</C></Index>
 <Index Key="last3"><C>last3</C></Index>
+<Index Key="time"><C>time</C></Index>
+<Index Key="memory_allocated"><C>memory_allocated</C></Index>
 <Index>previous result</Index>
 The normal interaction with &GAP; happens in the so-called
 <E>read-eval-print</E> loop.
@@ -154,8 +156,10 @@ gap> last3 + last2 * last;
 ]]></Example>
 <P/>
 Also in each statement the time spent by the last statement, whether it
-produced a value or not, is available in the variable <Ref Var="time"/>.
-This is an integer that holds the number of milliseconds.
+produced a value or not, is available in the variable <Ref
+Var="time"/>. This is an integer that holds the number of
+milliseconds. Similarly the amount of memory allocated during that
+statement (in bytes) is stored in the variable <Ref Var="memory_allocated"/>.
 
 </Section>
 

doc/ref/string.xml

@@ -521,6 +521,7 @@ vice versa. They are useful for examples of text encryption.
 <#Include Label="NumbersString">
 <#Include Label="StringNumbers">
 
+<#Include Label="StringOfMemoryAmount">
 </Section>
 
 

lib/gasman.gd

@@ -27,7 +27,7 @@
 ##  <P/>
 ##  The <C>full</C> component will be present if a full garbage collection
 ##  has taken place since &GAP; started. It contains information about
-##  the most recent full garbage collection. It is a record, with six
+##  the most recent full garbage collection. It is a record, with eight
 ##  components: <C>livebags</C> contains the number of bags which survived
 ##  the garbage collection; <C>livekb</C> contains the total number of
 ##  kilobytes occupied by those bags; <C>deadbags</C> contains the total
@@ -36,7 +36,10 @@
 ##  previous full garbage collection; <C>deadkb</C> contains the total
 ##  number of kilobytes occupied by those bags; <C>freekb</C> reports the
 ##  total number of kilobytes available in the &GAP; workspace for new
-##  objects and <C>totalkb</C> the actual size of the workspace.
+##  objects; <C>totalkb</C> reports the actual size of the workspace;
+##  <C>time</C> reports the CPU time in milliseconds spent on the last garbage
+##  collection and <C>cumulative</C> the total CPU time in milliseconds spent
+##  on that type of garbage collection since &GAP; started.
 ##  <P/>
 ##  These figures should be viewed with some caution. They are
 ##  stored internally in fixed length integer formats, and <C>deadkb</C>

lib/string.gd

@@ -834,6 +834,33 @@ DeclareGlobalFunction("LaTeXTable");
 
 BindGlobal("BHINT", MakeImm("\>\<"));
 
+#############################################################################
+##
+#F StringOfMemoryAmount( <m> )    returns an appropriate human-readable string 
+##                        representation of <m> bytes
+##
+##
+##  <#GAPDoc Label="StringOfMemoryAmount">
+##  <ManSection>
+##  <Func Name="StringOfMemoryAmount" Arg='numbytes'/>
+##
+##  <Description>
+##  This function returns a human-readable string representing 
+##  <Arg>numbytes</Arg> of memory. It is used in printing amounts of memory
+##  allocated by tests and benchmarks. Binary prefixes (representing powers of
+##  1024) are used.
+##  </Description>
+##  </ManSection>
+##  <Example><![CDATA[
+##  gap> StringOfMemoryAmount(123456789);
+##  "117MB"
+##  ]]></Example>
+##  <#/GAPDoc>
+
+
+DeclareGlobalFunction("StringOfMemoryAmount");
+
+
 #############################################################################
 ##
 #E

lib/string.gi

@@ -1202,6 +1202,37 @@ function(a,b)
     Error("concatenating strings via + is not supported, use Concatenation(<a>,<b>) instead");
 end);
 
+#############################################################################
+##
+#F StringOfMemoryAmount( <m> )    returns an appropriate human-readable string 
+##                        representation of <m> bytes
+##
+
+InstallGlobalFunction(StringOfMemoryAmount, function(m)
+    local  whole, frac, shift, s, units;
+    whole := m;
+    frac := 0;
+    shift := 0;
+    while whole >= 1024 do
+        frac := whole mod 1024;
+        whole := Int(whole / 1024);
+        shift := shift+1;
+    od;
+    s := ShallowCopy(String(whole));
+    if whole < 100 then
+        Append(s,".");
+        Append(s,String(Int(frac/102.4)));
+        if whole < 10 then
+            Append(s, String(Int(frac/10.24) mod 10));
+        fi;
+    fi;
+    units := ["B","KB","MB","GB","TB","PB","EB","YB","ZB"];    
+    Append(s, units[shift+1]);
+    return s;
+end);
+
+
+
 
 #############################################################################
 ##

lib/test.gi

@@ -567,14 +567,24 @@ end);
 ##
 
 InstallGlobalFunction( "TestDirectory", function(arg)
-  local basedirs, nopts, opts, files, newfiles, filetimes,
-        f, c, i, recurseFiles,
-        startTime, time, testResult, testTotal,
-        totalTime, STOP_TEST_CPY;
+    local  testTotal, totalTime, totalMem, STOP_TEST_CPY, 
+           basedirs, nopts, opts, testOptions, earlyStop, 
+           showProgress, suppressStatusMessage, exitGAP, c, files, 
+           filetimes, filemems, recurseFiles, f, i, startTime, 
+           startMem, testResult, time, mem, startGcTime, gctime,
+           totalGcTime, filegctimes, GcTime;
 
   testTotal := true;
   totalTime := 0;
+  totalMem := 0;
+  totalGcTime := 0;
 
+  GcTime := function()
+      local g;
+      g := GASMAN_STATS();    
+      return g[1][8] + g[2][8];    
+  end;
+
   STOP_TEST_CPY := STOP_TEST;
   STOP_TEST := function(arg) end;
 
@@ -609,6 +619,8 @@ InstallGlobalFunction( "TestDirectory", function(arg)
 
   files := [];
   filetimes := [];
+  filemems := [];  
+  filegctimes := [];  
 
   recurseFiles := function(dirs, prefix)
     local dircontents, testfiles, t, testrecs, shortName, recursedirs, d, subdirs;
@@ -658,6 +670,8 @@ InstallGlobalFunction( "TestDirectory", function(arg)
     fi;
 
     startTime := Runtime();
+    startMem := TotalMemoryAllocated();    
+    startGcTime := GcTime();    
     testResult := Test(files[i].name, opts.testOptions);
     if not(testResult) and opts.earlyStop then
       STOP_TEST := STOP_TEST_CPY;
@@ -673,19 +687,28 @@ InstallGlobalFunction( "TestDirectory", function(arg)
     testTotal := testTotal and testResult;
 
     time := Runtime() - startTime;
+    mem := TotalMemoryAllocated() - startMem;    
+    gctime := GcTime() - startGcTime;    
     filetimes[i] := time;
+    filemems[i] := mem;    
+    filegctimes[i] := gctime;    
     totalTime := totalTime + time;
+    totalMem := totalMem + mem;    
+    totalGcTime := totalGcTime + gctime;    
 
     if opts.showProgress then
-      Print( String( time, 8 ), " msec for ", files[i].shortName, "\n" );
+        Print( String( time, 8 ), " msec (",String(gctime),"ms GC) and ", 
+               StringOfMemoryAmount( mem ), 
+               " allocated for ", files[i].shortName, "\n" );
     fi;
   od;       
 
   STOP_TEST := STOP_TEST_CPY;
 
   Print("-----------------------------------\n");
   Print( "total",
-         String( totalTime, 10 ), " msec\n\n" );
+         String( totalTime, 10 ), " msec (",String( totalGcTime ),"ms GC) and ", 
+         StringOfMemoryAmount( totalMem )," allocated\n\n" );
 
   if not opts.suppressStatusMessage then
     if testTotal then

src/gap.c

@@ -148,6 +148,16 @@ UInt Last3;
 */
 UInt Time;
 
+/****************************************************************************
+**
+*V  MemoryAllocated . . . . . . . . . . . global variable  'memory_allocated'
+**
+**  'MemoryAllocated' is the global variable 'memory_allocated', 
+**  which is automatically assigned the amount of memory allocated while
+**  executing the last command.
+*/
+UInt MemoryAllocated;
+
 
 /****************************************************************************
 **
@@ -226,6 +236,7 @@ Obj Shell ( Obj context,
             Char *outFile)
 {
   UInt time = 0;
+  UInt mem = 0;
   UInt status;
   Obj evalResult;
   UInt dualSemicolon;
@@ -261,8 +272,10 @@ Obj Shell ( Obj context,
   while ( 1 ) {
 
     /* start the stopwatch                                             */
-    if (setTime)
-      time = SyTime();
+    if (setTime) {
+          time = SyTime();
+          mem = SizeAllBags;
+    }
 
     /* read and evaluate one command                                   */
     STATE(Prompt) = prompt;
@@ -339,8 +352,14 @@ Obj Shell ( Obj context,
     }
 
     /* stop the stopwatch                                          */
-    if (setTime)
+    if (setTime) {
       AssGVar( Time, INTOBJ_INT( SyTime() - time ) );
+      /* This should be correct for small allocated totals at least, 
+         even on 32 bits, but this functionality will never be very useful
+         on 32 bits */         
+      AssGVar(MemoryAllocated,
+              INTOBJ_INT((SizeAllBags - mem) % (1L << NR_SMALL_INT_BITS)));
+    }
 
     if (STATE(UserHasQuit))
       {
@@ -1944,6 +1963,14 @@ Obj FuncSHALLOW_SIZE (
     return ObjInt_UInt( SIZE_BAG( obj ) );
 }
 
+/****************************************************************************
+**
+*F  FuncTotalMemoryAllocated( <self> ) .expert function 'TotalMemoryAllocated'
+*/
+
+Obj FuncTotalMemoryAllocated( Obj self ) {
+    return INTOBJ_INT(SizeAllBags);
+}
 
 /****************************************************************************
 **
@@ -2871,6 +2898,7 @@ static StructGVarFunc GVarFuncs [] = {
     GVAR_FUNC(GASMAN_MESSAGE_STATUS, 0, ""),
     GVAR_FUNC(GASMAN_LIMITS, 0, ""),
     GVAR_FUNC(SHALLOW_SIZE, 1, "object"),
+    GVAR_FUNC(TotalMemoryAllocated, 0, ""),
     GVAR_FUNC(TNUM_OBJ, 1, "object"),
     GVAR_FUNC(TNUM_OBJ_INT, 1, "object"),
     GVAR_FUNC(OBJ_HANDLE, 1, "object"),
@@ -2969,7 +2997,9 @@ static Int PostRestore (
     Last2             = GVarName( "last2" );
     Last3             = GVarName( "last3" );
     Time              = GVarName( "time"  );
+    MemoryAllocated   = GVarName( "memory_allocated"  );
     AssGVar(Time, INTOBJ_INT(0));
+    AssGVar(MemoryAllocated, INTOBJ_INT(0));
     QUITTINGGVar      = GVarName( "QUITTING" );
 
     /* return success                                                      */

src/gasman.c

@@ -1251,9 +1251,7 @@ UInt ResizeBag (
 #ifdef COUNT_BAGS
     /* update the statistics                                               */
     InfoBags[type].sizeLive += new_size - old_size;
-    InfoBags[type].sizeAll  += new_size - old_size;
 #endif
-    SizeAllBags             += new_size - old_size;
 
     const Int diff = WORDS_BAG(new_size) - WORDS_BAG(old_size);
 
@@ -1303,6 +1301,12 @@ UInt ResizeBag (
             YoungBags += diff;
         AllocBags += diff;
 
+        // and increase the total amount allocated by the difference 
+#ifdef COUNT_BAGS
+        InfoBags[type].sizeAll  += new_size - old_size;
+#endif
+        SizeAllBags             += new_size - old_size;
+
         ADD_CANARY();
 
         header->size = new_size;
@@ -1335,6 +1339,12 @@ UInt ResizeBag (
         newHeader->flags = flags;
         newHeader->size = new_size;
 
+#ifdef COUNT_BAGS
+        InfoBags[type].sizeAll  += new_size;
+#endif
+        SizeAllBags             += new_size;
+
+
         CANARY_DISABLE_VALGRIND();
         /* if the bag is already on the changed bags list, keep it there   */
         if ( header->link != bag ) {
@@ -1354,15 +1364,12 @@ UInt ResizeBag (
         CANARY_ENABLE_VALGRIND();
 
         /* set the masterpointer                                           */
-        Bag * src = DATA(header);
-        Bag * end = src + WORDS_BAG(old_size);
         Bag * dst = DATA(newHeader);
         SET_PTR_BAG(bag, dst);
 
         /* copy the contents of the bag                                    */
-        while ( src < end )
-            *dst++ = *src++;
-
+        memmove((void *)dst, (void *)DATA(header),
+                sizeof(Obj) * WORDS_BAG(old_size));
     }
 
     /* return success                                                      */