More improvements to 'time' word

extra/tools/time/time.factor

@@ -1,36 +1,54 @@
 ! Copyright (C) 2003, 2008 Slava Pestov.
 ! See http://factorcode.org/license.txt for BSD license.
 USING: kernel math math.vectors memory io io.styles prettyprint
-namespaces system sequences assocs ;
+namespaces system sequences splitting assocs strings ;
 IN: tools.time
 
 : benchmark ( quot -- gctime runtime )
     millis >r call millis r> - ; inline
 
-: stats. ( data -- )
+: simple-table. ( values -- )
-    {
-        "Run time (ms):"
-        "Nursery GC time (ms):"
-        "Nursery GC #:"
-        "Aging GC time (ms):"
-        "Aging GC #:"
-        "Tenured GC time (ms):"
-        "Tenured GC #:"
-        "Cards scanned:"
-        "Decks scanned:"
-        "Code literal GC #:"
-        "Bytes copied:"
-        "Bytes collected:"
-    } swap zip
     standard-table-style [
         [
             [
-                [ [ write ] with-cell ] [ pprint-cell ] bi*
+                [
+                    dup string?
+                    [ [ write ] with-cell ]
+                    [ pprint-cell ]
+                    if
+                ] each
             ] with-row
-        ] assoc-each
+        ] each
     ] tabular-output ;
 
-: stats gc-stats millis prefix ;
+: time. ( data -- )
+    unclip
+    "==== RUNNING TIME" print nl pprint " ms" print nl
+    4 cut*
+    "==== GARBAGE COLLECTION" print nl
+    [
+        6 group
+        {
+            "GC count:"
+            "Cumulative GC time (ms):"
+            "Longest GC pause (ms):"
+            "Average GC pause (ms):"
+            "Objects copied:"
+            "Bytes copied:"
+        } prefix
+        flip
+        { "" "Nursery" "Aging" "Tenured" } prefix
+        simple-table.
+    ]
+    [
+        nl
+        {
+            "Total GC time (ms):"
+            "Cards scanned:"
+            "Decks scanned:"
+            "Code heap literal scans:"
+        } swap zip simple-table.
+    ] bi* ;
 
 : time ( quot -- )
-    stats >r call stats r> v- stats. ; inline
+    gc-reset millis >r call gc-stats millis r> - prefix time. ; inline

vm/data_gc.c

@@ -144,6 +144,13 @@ void set_data_heap(F_DATA_HEAP *data_heap_)
 	clear_cards(NURSERY,TENURED);
 }
 
+void gc_reset(void)
+{
+	int i;
+	for(i = 0; i < MAX_GEN_COUNT; i++)
+		memset(&gc_stats[i],0,sizeof(F_GC_STATS));
+}
+
 void init_data_heap(CELL gens,
 	CELL young_size,
 	CELL aging_size,
@@ -158,17 +165,13 @@ void init_data_heap(CELL gens,
 	extra_roots_region = alloc_segment(getpagesize());
 	extra_roots = extra_roots_region->start - CELLS;
 
-	nursery_gc_time = 0;
+	secure_gc = secure_gc_;
-	nursery_collections = 0;
+
-	aging_gc_time = 0;
+	gc_reset();
-	aging_collections = 0;
+
-	tenured_gc_time = 0;
-	tenured_collections = 0;
 	cards_scanned = 0;
 	decks_scanned = 0;
 	code_heap_scans = 0;
-	bytes_copied = 0;
-	secure_gc = secure_gc_;
 }
 
 /* Size of the object pointed to by a tagged pointer */
@@ -312,21 +315,16 @@ void collect_card(F_CARD *ptr, CELL gen, CELL here)
 	F_CARD c = *ptr;
 	CELL offset = (c & CARD_BASE_MASK);
 
-	if(offset == CARD_BASE_MASK)
+	if(offset != CARD_BASE_MASK)
 	{
-		/* if(c == 0xff)
+		CELL card_scan = (CELL)CARD_TO_ADDR(ptr) + offset;
-			critical_error("bad card",(CELL)ptr);
+		CELL card_end = (CELL)CARD_TO_ADDR(ptr + 1);
-		else */
+	
-			return;
+		while(card_scan < card_end && card_scan < here)
+			card_scan = collect_next(card_scan);
+	
+		cards_scanned++;
 	}
-
-	CELL card_scan = (CELL)CARD_TO_ADDR(ptr) + offset;
-	CELL card_end = (CELL)CARD_TO_ADDR(ptr + 1);
-
-	while(card_scan < card_end && card_scan < here)
-		card_scan = collect_next(card_scan);
-
-	cards_scanned++;
 }
 
 void collect_card_deck(F_DECK *deck, CELL gen, F_CARD mask, F_CARD unmask)
@@ -510,7 +508,11 @@ INLINE void *copy_untagged_object(void *pointer, CELL size)
 		longjmp(gc_jmp,1);
 	allot_barrier(newspace->here);
 	newpointer = allot_zone(newspace,size);
-	bytes_copied += size;
+
+	F_GC_STATS *s = &gc_stats[collecting_gen];
+	s->object_count++;
+	s->bytes_copied += size;
+
 	memcpy(newpointer,pointer,size);
 	return newpointer;
 }
@@ -641,7 +643,7 @@ CELL collect_next(CELL scan)
 INLINE void reset_generation(CELL i)
 {
 	F_ZONE *z = (i == NURSERY ? &nursery : &data_heap->generations[i]);
-	bytes_collected += (z->here - z->start);
+
 	z->here = z->start;
 	if(secure_gc)
 		memset((void*)z->start,69,z->size);
@@ -652,7 +654,9 @@ their allocation pointers and cards reset. */
 void reset_generations(CELL from, CELL to)
 {
 	CELL i;
-	for(i = from; i <= to; i++) reset_generation(i);
+	for(i = from; i <= to; i++)
+		reset_generation(i);
+
 	clear_cards(from,to);
 }
 
@@ -698,6 +702,13 @@ void begin_gc(CELL requested_bytes)
 
 void end_gc(CELL gc_elapsed)
 {
+	F_GC_STATS *s = &gc_stats[collecting_gen];
+
+	s->collections++;
+	s->gc_time += gc_elapsed;
+	if(s->max_gc_time < gc_elapsed)
+		s->max_gc_time = gc_elapsed;
+
 	if(growing_data_heap)
 	{
 		dealloc_data_heap(old_data_heap);
@@ -712,28 +723,12 @@ void end_gc(CELL gc_elapsed)
 		old-school Cheney collector */
 		if(collecting_gen != NURSERY)
 			reset_generations(NURSERY,collecting_gen - 1);
-
-		if(collecting_gen == TENURED)
-		{
-			tenured_collections++;
-			tenured_gc_time += gc_elapsed;
-			GC_PRINT(END_AGING_GC,aging_collections,cards_scanned);
-		}
-		else if(HAVE_AGING_P && collecting_gen == AGING)
-		{
-			aging_collections++;
-			aging_gc_time += gc_elapsed;
-			GC_PRINT(END_NURSERY_GC,nursery_collections,cards_scanned);
-		}
 	}
 	else
 	{
 		/* all generations up to and including the one
 		collected are now empty */
 		reset_generations(NURSERY,collecting_gen);
-
-		nursery_collections++;
-		nursery_gc_time += gc_elapsed;
 	}
 
 	if(collecting_gen == TENURED)
@@ -852,24 +847,38 @@ DEFINE_PRIMITIVE(gc)
 	gc();
 }
 
-/* Push total time spent on GC */
 DEFINE_PRIMITIVE(gc_stats)
 {
-	CELL array = tag_object(allot_array(ARRAY_TYPE,11,F));
+	GROWABLE_ARRAY(stats);
-	REGISTER_ROOT(array);
+
-	set_array_nth(untag_object(array),0,allot_cell(nursery_gc_time));
+	CELL i;
-	set_array_nth(untag_object(array),1,allot_cell(nursery_collections));
+	CELL total_gc_time = 0;
-	set_array_nth(untag_object(array),2,allot_cell(aging_gc_time));
+
-	set_array_nth(untag_object(array),3,allot_cell(aging_collections));
+	for(i = 0; i < MAX_GEN_COUNT; i++)
-	set_array_nth(untag_object(array),4,allot_cell(tenured_gc_time));
+	{
-	set_array_nth(untag_object(array),5,allot_cell(tenured_collections));
+		F_GC_STATS *s = &gc_stats[i];
-	set_array_nth(untag_object(array),6,tag_bignum(long_long_to_bignum(cards_scanned)));
+		GROWABLE_ADD(stats,allot_cell(s->collections));
-	set_array_nth(untag_object(array),7,tag_bignum(long_long_to_bignum(decks_scanned)));
+		GROWABLE_ADD(stats,allot_cell(s->gc_time));
-	set_array_nth(untag_object(array),8,allot_cell(code_heap_scans));
+		GROWABLE_ADD(stats,allot_cell(s->max_gc_time));
-	set_array_nth(untag_object(array),9,tag_bignum(long_long_to_bignum(bytes_copied)));
+		GROWABLE_ADD(stats,allot_cell(s->collections == 0 ? 0 : s->gc_time / s->collections));
-	set_array_nth(untag_object(array),10,tag_bignum(long_long_to_bignum(bytes_collected)));
+		GROWABLE_ADD(stats,allot_cell(s->object_count));
-	UNREGISTER_ROOT(array);
+		GROWABLE_ADD(stats,tag_bignum(long_long_to_bignum(s->bytes_copied)));
-	dpush(array);
+
+		total_gc_time += s->gc_time;
+	}
+
+	GROWABLE_ADD(stats,allot_cell(total_gc_time));
+	GROWABLE_ADD(stats,tag_bignum(long_long_to_bignum(cards_scanned)));
+	GROWABLE_ADD(stats,tag_bignum(long_long_to_bignum(decks_scanned)));
+	GROWABLE_ADD(stats,allot_cell(code_heap_scans));
+
+	GROWABLE_TRIM(stats);
+	dpush(stats);
+}
+
+DEFINE_PRIMITIVE(gc_reset)
+{
+	gc_reset();
 }
 
 DEFINE_PRIMITIVE(become)

vm/data_gc.h

@@ -138,6 +138,8 @@ void collect_cards(void);
 /* the oldest generation */
 #define TENURED (data_heap->gen_count-1)
 
+#define MAX_GEN_COUNT 3
+
 /* used during garbage collection only */
 F_ZONE *newspace;
 
@@ -158,16 +160,17 @@ void init_data_heap(CELL gens,
 	bool secure_gc_);
 
 /* statistics */
-CELL nursery_gc_time;
+typedef struct {
-CELL nursery_collections;
+	CELL collections;
-CELL aging_gc_time;
+	CELL gc_time;
-CELL aging_collections;
+	CELL max_gc_time;
-CELL tenured_gc_time;
+	CELL object_count;
-CELL tenured_collections;
+	u64 bytes_copied;
+} F_GC_STATS;
+
+F_GC_STATS gc_stats[MAX_GEN_COUNT];
 u64 cards_scanned;
 u64 decks_scanned;
-u64 bytes_copied;
-u64 bytes_collected;
 CELL code_heap_scans;
 
 /* only meaningful during a GC */
@@ -388,6 +391,7 @@ CELL collect_next(CELL scan);
 
 DECLARE_PRIMITIVE(gc);
 DECLARE_PRIMITIVE(gc_stats);
+DECLARE_PRIMITIVE(gc_reset);
 DECLARE_PRIMITIVE(become);
 
 CELL find_all_words(void);

vm/primitives.c

@@ -186,4 +186,5 @@ void *primitives[] = {
 	primitive_resize_float_array,
 	primitive_dll_validp,
 	primitive_unimplemented,
+	primitive_gc_reset,
 };