From b00d81e47bfcd4e25640ec294091272f98829774 Mon Sep 17 00:00:00 2001
From: Slava Pestov <slava@slava-pestovs-macbook-pro.local>
Date: Fri, 24 Apr 2009 09:44:29 -0500
Subject: [PATCH] Add time spent scanning cards to 'time' output

---
 basis/tools/time/time.factor |  3 ++-
 vm/data_gc.c                 | 14 ++++++++++----
 vm/data_gc.h                 |  1 +
 3 files changed, 13 insertions(+), 5 deletions(-)

diff --git a/basis/tools/time/time.factor b/basis/tools/time/time.factor
index 58fc531623..0d1d9f6fa1 100644
--- a/basis/tools/time/time.factor
+++ b/basis/tools/time/time.factor
@@ -10,7 +10,7 @@ IN: tools.time
 : time. ( data -- )
     unclip
     "==== RUNNING TIME" print nl 1000000 /f pprint " seconds" print nl
-    4 cut*
+    5 cut*
     "==== GARBAGE COLLECTION" print nl
     [
         6 group
@@ -32,6 +32,7 @@ IN: tools.time
             "Total GC time (us):"
             "Cards scanned:"
             "Decks scanned:"
+            "Card scan time (us):"
             "Code heap literal scans:"
         } swap zip simple-table.
     ] bi* ;
diff --git a/vm/data_gc.c b/vm/data_gc.c
index cc1df13d58..50f38bc881 100755
--- a/vm/data_gc.c
+++ b/vm/data_gc.c
@@ -115,9 +115,13 @@ void copy_gen_cards(CELL gen)
 old->new references */
 void copy_cards(void)
 {
+	u64 start = current_micros();
+
 	int i;
 	for(i = collecting_gen + 1; i < data_heap->gen_count; i++)
 		copy_gen_cards(i);
+
+	card_scan_time += (current_micros() - start);
 }
 
 /* Copy all tagged pointers in a range of memory */
@@ -435,7 +439,7 @@ void garbage_collection(CELL gen,
 		return;
 	}
 
-	s64 start = current_micros();
+	u64 start = current_micros();
 
 	performing_gc = true;
 	growing_data_heap = growing_data_heap_;
@@ -539,9 +543,10 @@ void primitive_gc_stats(void)
 		total_gc_time += s->gc_time;
 	}
 
-	GROWABLE_ARRAY_ADD(stats,tag_bignum(long_long_to_bignum(total_gc_time)));
-	GROWABLE_ARRAY_ADD(stats,tag_bignum(long_long_to_bignum(cards_scanned)));
-	GROWABLE_ARRAY_ADD(stats,tag_bignum(long_long_to_bignum(decks_scanned)));
+	GROWABLE_ARRAY_ADD(stats,tag_bignum(ulong_long_to_bignum(total_gc_time)));
+	GROWABLE_ARRAY_ADD(stats,tag_bignum(ulong_long_to_bignum(cards_scanned)));
+	GROWABLE_ARRAY_ADD(stats,tag_bignum(ulong_long_to_bignum(decks_scanned)));
+	GROWABLE_ARRAY_ADD(stats,tag_bignum(ulong_long_to_bignum(card_scan_time)));
 	GROWABLE_ARRAY_ADD(stats,allot_cell(code_heap_scans));
 
 	GROWABLE_ARRAY_TRIM(stats);
@@ -556,6 +561,7 @@ void clear_gc_stats(void)
 
 	cards_scanned = 0;
 	decks_scanned = 0;
+	card_scan_time = 0;
 	code_heap_scans = 0;
 }
 
diff --git a/vm/data_gc.h b/vm/data_gc.h
index feae26706d..52d8b603ad 100755
--- a/vm/data_gc.h
+++ b/vm/data_gc.h
@@ -28,6 +28,7 @@ typedef struct {
 F_GC_STATS gc_stats[MAX_GEN_COUNT];
 u64 cards_scanned;
 u64 decks_scanned;
+u64 card_scan_time;
 CELL code_heap_scans;
 
 /* What generation was being collected when copy_code_heap_roots() was last