From: hboehm <hboehm>
Date: Tue, 11 Nov 2008 00:24:52 +0000 (+0000)
Subject: 2008-11-10  Hans Boehm <Hans.Boehm@hp.com> (Really Ivan Maidansky)
X-Git-Tag: gc7_2alpha2~45
X-Git-Url: https://granicus.if.org/sourcecode?a=commitdiff_plain;h=ba6f1a2872fe24b4fad83180104c25d5aee6505b;p=gc

2008-11-10  Hans Boehm <Hans.Boehm@hp.com> (Really Ivan Maidansky)
	* alloc.c (GC_try_to_collect_inner): Don't print redundant
	GC_bytes_allocd and GC_gc_no.
	(GC_stopped_mark): Print average world stop time.
	* include/private/gc_priv.h (MS_TIME_DIFF): Add cast.
---

diff --git a/ChangeLog b/ChangeLog
index 90ed1262..75e10a20 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,9 @@
+2008-11-10  Hans Boehm <Hans.Boehm@hp.com> (Really Ivan Maidansky)
+	* alloc.c (GC_try_to_collect_inner): Don't print redundant
+	GC_bytes_allocd and GC_gc_no.
+	(GC_stopped_mark): Print average world stop time.
+	* include/private/gc_priv.h (MS_TIME_DIFF): Add cast.
+
 2008-11-10  Hans Boehm <Hans.Boehm@hp.com> (Really mostly Ivan Maidansky)
 	* misc.c, doc/README.environment: Add support  for
 	GC_FREE_SPACE_DIVISOR and GC-disable-incremental.
diff --git a/alloc.c b/alloc.c
index 8596a17b..f40282a6 100644
--- a/alloc.c
+++ b/alloc.c
@@ -340,9 +340,7 @@ GC_bool GC_try_to_collect_inner(GC_stop_func stop_func)
 #   ifndef SMALL_CONFIG
       if (GC_print_stats) {
 	GET_TIME(start_time);
-	GC_log_printf(
-	   "Initiating full world-stop collection %lu after %ld allocd bytes\n",
-	   (unsigned long)GC_gc_no+1, (long)GC_bytes_allocd);
+	GC_log_printf("Initiating full world-stop collection!\n");
       }
 #   endif
     GC_promote_black_lists();
@@ -463,6 +461,21 @@ GC_API int GC_CALL GC_collect_a_little(void)
 #ifdef MAKE_BACK_GRAPH
   void GC_build_back_graph(void);
 #endif
+
+#ifndef SMALL_CONFIG
+  /* Variables for world-stop average delay time statistic computation.	*/
+  /* "divisor" is incremented every world-stop and halved when reached	*/
+  /* its maximum (or upon "total_time" oveflow).			*/
+  STATIC unsigned world_stopped_total_time = 0;
+  STATIC unsigned world_stopped_total_divisor = 0;
+# ifndef MAX_TOTAL_TIME_DIVISOR
+    /* We shall not use big values here (so "outdated" delay time	*/
+    /* values would have less impact on "average" delay time value than	*/
+    /* newer ones).							*/
+#   define MAX_TOTAL_TIME_DIVISOR 1000
+# endif
+#endif
+
 /*
  * Assumes lock is held, signals are disabled.
  * We stop the world.
@@ -475,17 +488,20 @@ GC_bool GC_stopped_mark(GC_stop_func stop_func)
     int dummy;
 #   ifndef SMALL_CONFIG
       CLOCK_TYPE start_time, current_time;
-	
-      if (GC_print_stats)
-	GET_TIME(start_time);
 #   endif
-
+	
 #   if !defined(REDIRECT_MALLOC) && (defined(MSWIN32) || defined(MSWINCE))
         GC_add_current_malloc_heap();
 #   endif
 #   if defined(REGISTER_LIBRARIES_EARLY)
         GC_cond_register_dynamic_libraries();
 #   endif
+
+#   ifndef SMALL_CONFIG
+      if (GC_print_stats)
+	GET_TIME(start_time);
+#   endif
+
     STOP_WORLD();
     IF_THREADS(GC_world_stopped = TRUE);
     if (GC_print_stats) {
@@ -540,9 +556,29 @@ GC_bool GC_stopped_mark(GC_stop_func stop_func)
     START_WORLD();
 #   ifndef SMALL_CONFIG
       if (GC_print_stats) {
+	unsigned long time_diff;
+	unsigned total_time, divisor;
 	GET_TIME(current_time);
-	GC_log_printf("World-stopped marking took %lu msecs\n",
-		      MS_TIME_DIFF(current_time,start_time));
+	time_diff = MS_TIME_DIFF(current_time,start_time);
+
+	/* Compute new world-stop delay total time */
+	total_time = world_stopped_total_time;
+	divisor = world_stopped_total_divisor;
+	if ((int)total_time < 0 || divisor >= MAX_TOTAL_TIME_DIVISOR) {
+	  /* Halve values if overflow occurs */
+	  total_time >>= 1;
+	  divisor >>= 1;
+	}
+	total_time += time_diff < (((unsigned)-1) >> 1) ?
+			(unsigned)time_diff : ((unsigned)-1) >> 1;
+	/* Update old world_stopped_total_time and its divisor */
+	world_stopped_total_time = total_time;
+	world_stopped_total_divisor = ++divisor;
+	
+	GC_ASSERT(divisor != 0);
+	GC_log_printf(
+		"World-stopped marking took %lu msecs (%lu in average)\n",
+		time_diff, total_time / divisor);
       }
 #   endif
     return(TRUE);
diff --git a/include/private/gc_priv.h b/include/private/gc_priv.h
index b803469e..a86f7653 100644
--- a/include/private/gc_priv.h
+++ b/include/private/gc_priv.h
@@ -234,8 +234,9 @@ void GC_print_callers(struct callinfo info[NFRAMES]);
 #   define GET_TIME(x) { struct rusage rusage; \
 			 getrusage (RUSAGE_SELF,  &rusage); \
 			 x = rusage.ru_utime; }
-#   define MS_TIME_DIFF(a,b) ((double) (a.tv_sec - b.tv_sec) * 1000.0 \
-                               + (double) (a.tv_usec - b.tv_usec) / 1000.0)
+#   define MS_TIME_DIFF(a,b) \
+		((unsigned long)((double) (a.tv_sec - b.tv_sec) * 1000.0 \
+                               + (double) (a.tv_usec - b.tv_usec) / 1000.0))
 #else /* !BSD_TIME */
 # if defined(MSWIN32) || defined(MSWINCE)
 #   include <windows.h>