[pypy-commit] stmgc default: Replace fprintf(stderr, ...) with dprintf((...)), which is turned off if

arigo noreply at buildbot.pypy.org
Mon Jun 24 17:05:55 CEST 2013


Author: Armin Rigo <arigo at tunes.org>
Branch: 
Changeset: r264:104bd28d6f04
Date: 2013-06-24 17:05 +0200
http://bitbucket.org/pypy/stmgc/changeset/104bd28d6f04/

Log:	Replace fprintf(stderr, ...) with dprintf((...)), which is turned
	off if _GC_DEBUG is not defined. Now the "build-demo*" executables
	are incredibly fast --- almost all the time was spent printing this
	debug stuff.

diff --git a/c4/Makefile b/c4/Makefile
--- a/c4/Makefile
+++ b/c4/Makefile
@@ -2,11 +2,14 @@
 # Makefile for the demos.
 #
 
-build: build-demo1 build-demo2 build-demo_random
-debug: debug-demo1 debug-demo2 debug-demo_random
+BUILD_EXE = build-demo1 build-demo2 build-demo_random
+DEBUG_EXE = debug-demo1 debug-demo2 debug-demo_random
+
+build: $(BUILD_EXE)
+debug: $(DEBUG_EXE)
 
 clean:
-	rm -f debug-demo1
+	rm -f $(BUILD_EXE) $(DEBUG_EXE)
 
 
 H_FILES = atomic_ops.h stmgc.h stmimpl.h \
@@ -16,9 +19,10 @@
 C_FILES = et.c lists.c steal.c nursery.c gcpage.c \
           stmsync.c dbgmem.c fprintcolor.c
 
-DEBUG = -g -DGC_NURSERY=0x10000  #-D_GC_DEBUG=1
+DEBUG = -g -DGC_NURSERY=0x10000 -D_GC_DEBUG=1
 
 
+# note that we don't say -DNDEBUG, so that asserts should still be compiled it
 build-%: %.c ${H_FILES} ${C_FILES} stmgc.c
 	gcc -lrt -pthread -O2 -g $< -o build-$* -Wall stmgc.c
 
diff --git a/c4/atomic_ops.h b/c4/atomic_ops.h
--- a/c4/atomic_ops.h
+++ b/c4/atomic_ops.h
@@ -99,13 +99,13 @@
 #if 0    /* fprinting versions */
 # define spinlock_acquire(lock, targetvalue)                            \
     do { if (bool_cas(&(lock), 0, (targetvalue))) {                     \
-             fprintf(stderr, "<<< locked %d\n", (int)targetvalue);      \
+             dprintf(("<<< locked %d\n", (int)targetvalue));            \
              break;                                                     \
          }                                                              \
          do { smp_spinloop(); } while (ACCESS_ONCE(lock));              \
     } while (1)
 # define spinlock_release(lock)                                         \
-    do { fprintf(stderr, "unlocked >>>\n"); smp_wmb();                  \
+    do { dprintf(("unlocked >>>\n")); smp_wmb();                        \
          assert((lock) != 0); (lock) = 0; } while (0)
 #else
 # define spinlock_acquire(lock, targetvalue)                    \
diff --git a/c4/dbgmem.c b/c4/dbgmem.c
--- a/c4/dbgmem.c
+++ b/c4/dbgmem.c
@@ -22,7 +22,7 @@
     intptr_t align = ((intptr_t)p) & (PAGE_SIZE-1);
     p = ((char *)p) - align;
     sz += align;
-    fprintf(stderr, "dbgmem: %p, %ld, %d\n", p, (long)sz, prot);
+    dprintf(("dbgmem: %p, %ld, %d\n", p, (long)sz, prot));
     int err = mprotect(p, sz, prot);
     assert(err == 0);
 }
@@ -35,8 +35,7 @@
         zone_start = mmap(NULL, MMAP_TOTAL, PROT_NONE,
                           MAP_PRIVATE | MAP_ANONYMOUS, -1, 0);
         if (zone_start == NULL || zone_start == MAP_FAILED) {
-            fprintf(stderr, "not enough memory: mmap() failed\n");
-            abort();
+            stm_fatalerror("not enough memory: mmap() failed\n");
         }
         zone_current = zone_start;
         zone_end = zone_start + MMAP_TOTAL;
@@ -48,9 +47,8 @@
     char *result = zone_current;
     zone_current += nb_pages * PAGE_SIZE;
     if (zone_current > zone_end) {
-        fprintf(stderr, "dbgmem.c: %ld MB of memory have been exausted\n",
-                (long)(MMAP_TOTAL / (1024*1024)));
-        abort();
+        stm_fatalerror("dbgmem.c: %ld MB of memory have been exausted\n",
+                       (long)(MMAP_TOTAL / (1024*1024)));
     }
     pthread_mutex_unlock(&malloc_mutex);
 
diff --git a/c4/demo1.c b/c4/demo1.c
--- a/c4/demo1.c
+++ b/c4/demo1.c
@@ -66,7 +66,7 @@
 
       r_n = (struct node *)stm_read_barrier((gcptr)r_n->next);
       long v = r_n->value;
-      fprintf(stderr, "\t\t\t\t{ %ld, %p }\n", v, r_n->next);
+      dprintf(("\t\t\t\t{ %ld, %p }\n", v, r_n->next));
       assert(0 <= v && v < UPPER_BOUND * NUMTHREADS);
       int tn = v / UPPER_BOUND;
       assert(seen[tn] == v % UPPER_BOUND);
@@ -95,10 +95,10 @@
     assert(seen[nvalue / UPPER_BOUND] == nvalue % UPPER_BOUND);
     w_newnode->value = nvalue;
     w_newnode->next = NULL;
-    fprintf(stderr, "DEMO1: %p->value = %ld\n", w_newnode, nvalue);
+    dprintf(("DEMO1: %p->value = %ld\n", w_newnode, nvalue));
 
     struct node *w_last = (struct node *)stm_write_barrier((gcptr)last);
-    fprintf(stderr, "DEMO1:   %p->next = %p\n", w_last, w_newnode);
+    dprintf(("DEMO1:   %p->next = %p\n", w_last, w_newnode));
     w_last->next = w_newnode;
 
     return 0;   /* return from stm_perform_transaction() */
@@ -118,7 +118,7 @@
 
     start = thr_mynum++;   /* protected by being inevitable here */
     start *= UPPER_BOUND;
-    fprintf(stderr, "THREAD STARTING: start = %d\n", start);
+    dprintf(("THREAD STARTING: start = %d\n", start));
 
     w_node = (struct node *)stm_allocate(sizeof(struct node),
                                          GCTID_STRUCT_NODE);
diff --git a/c4/demo2.c b/c4/demo2.c
--- a/c4/demo2.c
+++ b/c4/demo2.c
@@ -137,7 +137,7 @@
     stm_initialize();
     
     thr_mynum++;   /* protected by being inevitable here */
-    fprintf(stderr, "THREAD STARTING\n");
+    dprintf(("THREAD STARTING\n"));
     
     
     while (check_sorted() == -1) {
diff --git a/c4/demo_random.c b/c4/demo_random.c
--- a/c4/demo_random.c
+++ b/c4/demo_random.c
@@ -417,7 +417,7 @@
     setup_thread();
     
     thr_mynum++;   /* protected by being inevitable here */
-    fprintf(stderr, "THREAD STARTING\n");
+    dprintf(("THREAD STARTING\n"));
 
     run_me();
     
diff --git a/c4/et.c b/c4/et.c
--- a/c4/et.c
+++ b/c4/et.c
@@ -144,7 +144,7 @@
           */
           if (FXCACHE_AT(P) == P)
             {
-              fprintf(stderr, "read_barrier: %p -> %p fxcache\n", G, P);
+              dprintf(("read_barrier: %p -> %p fxcache\n", G, P));
               return P;
             }
         }
@@ -164,7 +164,7 @@
           P = item->val;
           assert(!(P->h_tid & GCFLAG_PUBLIC));
           assert(is_private(P));
-          fprintf(stderr, "read_barrier: %p -> %p public_to_private\n", G, P);
+          dprintf(("read_barrier: %p -> %p public_to_private\n", G, P));
           return P;
 
         no_private_obj:
@@ -190,13 +190,13 @@
           ValidateNow(d);                  // try to move start_time forward
           goto restart_all_public;         // restart searching from P
         }
-      fprintf(stderr, "read_barrier: %p -> %p public\n", G, P);
+      dprintf(("read_barrier: %p -> %p public\n", G, P));
     }
   else
     {
       /* Not private and not public: it's a protected object
        */
-      fprintf(stderr, "read_barrier: %p -> %p protected\n", G, P);
+      dprintf(("read_barrier: %p -> %p protected\n", G, P));
 
       /* The risks are not high, but in parallel it's possible for the
          object to be stolen by another thread and become public, after
@@ -205,7 +205,7 @@
       /*assert(P->h_revision & 1);*/
     }
 
-  fprintf(stderr, "readobj: %p\n", P);
+  dprintf(("readobj: %p\n", P));
   assert(!(P->h_tid & GCFLAG_STUB));
   gcptrlist_insert(&d->list_of_read_objects, P);
 
@@ -227,7 +227,7 @@
          we reach any kind of object, even a public object, in case it
          was stolen.  So we just repeat the whole procedure. */
       P = (gcptr)(v - 2);
-      fprintf(stderr, "read_barrier: %p -> %p via stub\n  ", G, P);
+      dprintf(("read_barrier: %p -> %p via stub\n  ", G, P));
 
       if (UNLIKELY((P->h_revision != stm_private_rev_num) &&
                    (FXCACHE_AT(P) != P)))
@@ -238,7 +238,7 @@
   else
     {
       /* stealing */
-      fprintf(stderr, "read_barrier: %p -> stealing %p...\n  ", G, P);
+      dprintf(("read_barrier: %p -> stealing %p...\n  ", G, P));
       stm_steal_stub(P);
 
       assert(P->h_tid & GCFLAG_PUBLIC);
@@ -262,12 +262,12 @@
       assert(!(privobj->h_tid & GCFLAG_PUBLIC));
       assert(is_private(privobj));
       if (P != org_pubobj)
-        fprintf(stderr, "| actually %p ", org_pubobj);
+        dprintf(("| actually %p ", org_pubobj));
       if (from_stolen)
-        fprintf(stderr, "-stolen");
+        dprintf(("-stolen"));
       else
         assert(org_pubobj->h_tid & GCFLAG_PUBLIC_TO_PRIVATE);
-      fprintf(stderr, "-public_to_private-> %p private\n", privobj);
+      dprintf(("-public_to_private-> %p private\n", privobj));
       return privobj;
     }
   return NULL;
@@ -308,19 +308,19 @@
   struct tx_descriptor *d = thread_descriptor;
   if (P->h_tid & GCFLAG_STUB)
     {
-      fprintf(stderr, "S");
+      dprintf(("S"));
     }
   int is_old = (P->h_tid & GCFLAG_OLD) != 0;
   int in_nurs = (d->nursery_base <= (char*)P && ((char*)P) < d->nursery_end);
   if (in_nurs)
     {
       assert(!is_old);
-      fprintf(stderr, "Y ");
+      dprintf(("Y "));
     }
   else
     {
       assert(is_old);
-      fprintf(stderr, "O ");
+      dprintf(("O "));
     }
 }
 
@@ -330,14 +330,14 @@
   struct tx_descriptor *d = thread_descriptor;
   revision_t v;
 
-  fprintf(stderr, "_stm_nonrecord_barrier: %p ", P);
+  dprintf(("_stm_nonrecord_barrier: %p ", P));
   _check_flags(P);
 
  restart_all:
   if (P->h_revision == stm_private_rev_num)
     {
       /* private */
-      fprintf(stderr, "private\n");
+      dprintf(("private\n"));
       return P;
     }
 
@@ -345,22 +345,22 @@
     {
       /* private too, with a backup copy */
       assert(IS_POINTER(P->h_revision));
-      fprintf(stderr, "private_from_protected\n");
+      dprintf(("private_from_protected\n"));
       return P;
     }
 
   if (P->h_tid & GCFLAG_PUBLIC)
     {
-      fprintf(stderr, "public ");
+      dprintf(("public "));
 
       while (v = P->h_revision, IS_POINTER(v))
         {
           if (P->h_tid & GCFLAG_NURSERY_MOVED)
-            fprintf(stderr, "nursery_moved ");
+            dprintf(("nursery_moved "));
 
           if (v & 2)
             {
-              fprintf(stderr, "stub ");
+              dprintf(("stub "));
               gcptr L = _find_public_to_private(P);
               if (L != NULL)
                 return L;
@@ -369,7 +369,7 @@
 
           P = (gcptr)v;
           assert(P->h_tid & GCFLAG_PUBLIC);
-          fprintf(stderr, "-> %p public ", P);
+          dprintf(("-> %p public ", P));
           _check_flags(P);
         }
 
@@ -379,14 +379,14 @@
 
       if (UNLIKELY(v > d->start_time))
         {
-          fprintf(stderr, "too recent!\n");
+          dprintf(("too recent!\n"));
           return NULL;   // object too recent
         }
-      fprintf(stderr, "\n");
+      dprintf(("\n"));
     }
   else
     {
-      fprintf(stderr, "protected\n");
+      dprintf(("protected\n"));
     }
   return P;
 
@@ -394,23 +394,23 @@
   if (STUB_THREAD(P) == d->public_descriptor)
     {
       P = (gcptr)(v - 2);
-      fprintf(stderr, "-> %p ", P);
+      dprintf(("-> %p ", P));
       _check_flags(P);
     }
   else
     {
       P = (gcptr)(v - 2);
       /* cannot _check_flags(P): foreign! */
-      fprintf(stderr, "-foreign-> %p ", P);
+      dprintf(("-foreign-> %p ", P));
       if (P->h_tid & GCFLAG_PRIVATE_FROM_PROTECTED)
         {
           P = (gcptr)P->h_revision;     /* the backup copy */
           /* cannot _check_flags(P): foreign! */
-          fprintf(stderr, "-backup-> %p ", P);
+          dprintf(("-backup-> %p ", P));
         }
       if (!(P->h_tid & GCFLAG_PUBLIC))
         {
-          fprintf(stderr, "protected by someone else!\n");
+          dprintf(("protected by someone else!\n"));
           return (gcptr)-1;
         }
     }
@@ -467,7 +467,7 @@
   P->h_revision = (revision_t)B;
 
   gcptrlist_insert(&d->private_from_protected, P);
-  fprintf(stderr, "private_from_protected: insert %p (backup %p)\n", P, B);
+  dprintf(("private_from_protected: insert %p (backup %p)\n", P, B));
 
   return P;   /* always returns its arg: the object is converted in-place */
 }
@@ -480,7 +480,7 @@
 #ifdef _GC_DEBUG
   wlog_t *entry;
   G2L_FIND(d->public_to_private, R, entry, goto not_found);
-  assert(!"R is already in public_to_private");
+  stm_fatalerror("R is already in public_to_private\n");
  not_found:
 #endif
 
@@ -513,8 +513,8 @@
   assert(stm_private_rev_num < 0);
   assert(stm_private_rev_num & 1);
   g2l_insert(&d->public_to_private, R, L);
-  fprintf(stderr, "write_barrier: adding %p -> %p to public_to_private\n",
-          R, L);
+  dprintf(("write_barrier: adding %p -> %p to public_to_private\n",
+           R, L));
 
   /* must remove R from the read_barrier_cache, because returning R is no
      longer a valid result */
@@ -603,7 +603,7 @@
 
   spinlock_release(d->public_descriptor->collection_lock);
 
-  fprintf(stderr, "write_barrier: %p -> %p -> %p\n", P, R, W);
+  dprintf(("write_barrier: %p -> %p -> %p\n", P, R, W));
 
   return W;
 }
@@ -661,8 +661,8 @@
             }
           else
             {
-              fprintf(stderr, "validation failed: "
-                      "%p has a more recent revision\n", R);
+              dprintf(("validation failed: "
+                       "%p has a more recent revision\n", R));
               return 0;
             }
         }
@@ -696,8 +696,8 @@
 
                      For now we always abort.
                   */
-                  fprintf(stderr, "validation failed: "
-                          "%p is locked by another thread\n", R);
+                  dprintf(("validation failed: "
+                           "%p is locked by another thread\n", R));
                   return 0;
                 }
             }
@@ -709,7 +709,7 @@
 static void ValidateNow(struct tx_descriptor *d)
 {
   d->start_time = GetGlobalCurTime(d);   // copy from the global time
-  fprintf(stderr, "et.c: ValidateNow: %ld\n", (long)d->start_time);
+  dprintf(("et.c: ValidateNow: %ld\n", (long)d->start_time));
 
   /* subtle: we have to normalize stolen objects, because doing so
      might add a few extra objects in the list_of_read_objects */
@@ -792,11 +792,8 @@
         {
           if (_stm_decode_abort_info(d, elapsed_time,
                                      num, d->longest_abort_info) != size)
-            {
-              fprintf(stderr,
-                      "during stm abort: object mutated unexpectedly\n");
-              abort();
-            }
+            stm_fatalerror("during stm abort: object mutated unexpectedly\n");
+
           d->longest_abort_info_time = elapsed_time;
         }
     }
@@ -836,19 +833,15 @@
   /* release the lock */
   spinlock_release(d->public_descriptor->collection_lock);
 
-  fprintf(stderr,
-          "\n"
+  dprintf(("\n"
           "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n"
           "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n"
           "!!!!!!!!!!!!!!!!!!!!!  [%lx] abort %d\n"
           "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n"
           "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n"
-          "\n", (long)d->public_descriptor_index, num);
+          "\n", (long)d->public_descriptor_index, num));
   if (num != ABRT_MANUAL && d->max_aborts >= 0 && !d->max_aborts--)
-    {
-      fprintf(stderr, "unexpected abort!\n");
-      abort();
-    }
+    stm_fatalerror("unexpected abort!\n");
 
   // notifies the CPU that we're potentially in a spin loop
   SpinLoop(SPLP_ABORT);
@@ -862,7 +855,7 @@
 {
   if (d->active >= 0)
     {
-      fprintf(stderr, "abort %d after collect!\n", reason);
+      dprintf(("abort %d after collect!\n", reason));
       assert(d->active == 1);   /* not 2, which means inevitable */
       d->active = -reason;
     }
@@ -998,7 +991,7 @@
       L->h_revision = expected;
 
 #ifdef DUMP_EXTRA
-      fprintf(stderr, "%p->h_revision = %p (CancelLocks)\n", R, (gcptr)v);
+      dprintf(("%p->h_revision = %p (CancelLocks)\n", R, (gcptr)v));
 #endif
       assert(R->h_revision == my_lock);
       ACCESS_ONCE(R->h_revision) = v;
@@ -1028,8 +1021,8 @@
       assert(L->h_revision != localrev);   /* modified by AcquireLocks() */
 
 #ifdef DUMP_EXTRA
-      fprintf(stderr, "%p->h_revision = %p (UpdateChainHeads)\n",
-              L, (gcptr)new_revision);
+      dprintf(("%p->h_revision = %p (UpdateChainHeads)\n",
+               L, (gcptr)new_revision));
 #endif
       L->h_revision = new_revision;
 
@@ -1068,9 +1061,8 @@
       assert(R->h_revision != localrev);
 
 #ifdef DUMP_EXTRA
-      fprintf(stderr, "%p->h_revision = %p (stub to %p)\n",
-              R, (gcptr)v, (gcptr)item->val->h_revision);
-      /*mark*/
+      dprintf(("%p->h_revision = %p (stub to %p)\n",
+               R, (gcptr)v, (gcptr)item->val->h_revision));
 #endif
       ACCESS_ONCE(R->h_revision) = v;
 
@@ -1139,13 +1131,13 @@
       else
         {
           stmgcpage_free(B);
-          fprintf(stderr, "commit: free backup at %p\n", B);
+          dprintf(("commit: free backup at %p\n", B));
         }
     };
   gcptrlist_clear(&d->private_from_protected);
   d->num_private_from_protected_known_old = 0;
   d->num_read_objects_known_old = 0;
-  fprintf(stderr, "private_from_protected: clear (commit)\n");
+  dprintf(("private_from_protected: clear (commit)\n"));
 }
 
 void AbortPrivateFromProtected(struct tx_descriptor *d)
@@ -1201,13 +1193,13 @@
                  size - offsetof(struct stm_object_s, h_revision));
           assert(!(P->h_tid & GCFLAG_BACKUP_COPY));
           stmgcpage_free(B);
-          fprintf(stderr, "abort: free backup at %p\n", B);
+          dprintf(("abort: free backup at %p\n", B));
         }
     };
   gcptrlist_clear(&d->private_from_protected);
   d->num_private_from_protected_known_old = 0;
   d->num_read_objects_known_old = 0;
-  fprintf(stderr, "private_from_protected: clear (abort)\n");
+  dprintf(("private_from_protected: clear (abort)\n"));
 }
 
 void CommitTransaction(void)
@@ -1227,8 +1219,7 @@
       cur_time = d->start_time;
       if (!bool_cas(&global_cur_time, cur_time + 1, cur_time + 2))
         {
-          assert(!"global_cur_time modified even though we are inev.");
-          abort();
+          stm_fatalerror("global_cur_time modified even though we are inev\n");
         }
       inev_mutex_release();
     }
@@ -1265,11 +1256,11 @@
   d->setjmp_buf = NULL;
   gcptrlist_clear(&d->list_of_read_objects);
 
-  fprintf(stderr, "\n"
+  dprintf(("\n"
           "*************************************\n"
           "**************************************  committed %ld\n"
           "*************************************\n",
-          (long)cur_time);
+           (long)cur_time));
 
   revision_t localrev = stm_private_rev_num;
   //UpdateProtectedChainHeads(d, cur_time, localrev);
@@ -1278,7 +1269,7 @@
   revision_t newrev = -(cur_time + 1);
   assert(newrev & 1);
   ACCESS_ONCE(stm_private_rev_num) = newrev;
-  fprintf(stderr, "%p: stm_local_revision = %ld\n", d, (long)newrev);
+  dprintf(("%p: stm_local_revision = %ld\n", d, (long)newrev));
   assert(d->private_revision_ref == &stm_private_rev_num);
   assert(d->read_barrier_cache_ref == &stm_read_barrier_cache);
 
@@ -1326,8 +1317,8 @@
                 (XXX statically we should know when we're outside
                 a transaction) */
 
-  fprintf(stderr, "[%lx] inevitable: %s\n",
-          (long)d->public_descriptor_index, why);
+  dprintf(("[%lx] inevitable: %s\n",
+           (long)d->public_descriptor_index, why));
 
   cur_time = acquire_inev_mutex_and_mark_global_cur_time(d);
   if (d->start_time != cur_time)
@@ -1458,7 +1449,7 @@
 void _stm_test_forget_previous_state(void)
 {
   /* debug: reset all global states, between tests */
-  fprintf(stderr, "=======================================================\n");
+  dprintf(("=======================================================\n"));
   assert(thread_descriptor == NULL);
   memset(stm_descriptor_array, 0, sizeof(stm_descriptor_array));
   descriptor_array_free_list = 0;
@@ -1484,9 +1475,8 @@
 {
   if (GCFLAG_PREBUILT != PREBUILT_FLAGS)
     {
-      fprintf(stderr, "fix PREBUILT_FLAGS in stmgc.h by giving "
-                      "it the same value as GCFLAG_PREBUILT!\n");
-      abort();
+      stm_fatalerror("fix PREBUILT_FLAGS in stmgc.h by giving "
+                     "it the same value as GCFLAG_PREBUILT!\n");
     }
 
   if (thread_descriptor == NULL)
@@ -1515,9 +1505,8 @@
           /* no item in the free list */
           descriptor_array_free_list = i + 1;
           if (descriptor_array_free_list == MAX_THREADS) {
-              fprintf(stderr, "error: too many threads at the same time "
-                              "in this process");
-              abort();
+              stm_fatalerror("error: too many threads at the same time "
+                             "in this process");
           }
           pd = stm_malloc(sizeof(struct tx_public_descriptor));
           memset(pd, 0, sizeof(struct tx_public_descriptor));
@@ -1540,8 +1529,8 @@
       stm_tx_head = d;
       thread_descriptor = d;
 
-      fprintf(stderr, "[%lx] pthread %lx starting\n",
-              (long)d->public_descriptor_index, (long)pthread_self());
+      dprintf(("[%lx] pthread %lx starting\n",
+               (long)d->public_descriptor_index, (long)pthread_self()));
 
       stmgcpage_init_tls();
       stmgcpage_release_global_lock();
@@ -1611,7 +1600,7 @@
                      d->num_spinloops[i]);
 
     p += sprintf(p, "]\n");
-    fprintf(stderr, "%s", line);
+    dprintf(("%s", line));
 
     stm_free(d, sizeof(struct tx_descriptor));
 }
diff --git a/c4/fprintcolor.c b/c4/fprintcolor.c
--- a/c4/fprintcolor.c
+++ b/c4/fprintcolor.c
@@ -1,10 +1,31 @@
 #include "stmimpl.h"
 
+
+void stm_fatalerror(const char *format, ...)
+{
+    va_list ap;
+
+#ifdef _GC_DEBUG
+    dprintf(("STM Subsystem: Fatal Error\n"));
+#else
+    fprintf(stderr, "STM Subsystem: Fatal Error\n");
+#endif
+
+    va_start(ap, format);
+    vfprintf(stderr, format, ap);
+    va_end(ap);
+
+    abort();
+}
+
+
+#ifdef _GC_DEBUG
+
 static __thread revision_t tcolor = 0;
 static revision_t tnextid = 0;
 
 
-int threadcolor_fprintf(FILE *stream, const char *format, ...)
+int threadcolor_printf(const char *format, ...)
 {
     char buffer[2048];
     va_list ap;
@@ -26,7 +47,9 @@
     va_end(ap);
 
     strcpy(buffer + size + result, "\033[0m");
-    fputs(buffer, stream);
+    fputs(buffer, stderr);
 
     return result;
 }
+
+#endif
diff --git a/c4/fprintcolor.h b/c4/fprintcolor.h
--- a/c4/fprintcolor.h
+++ b/c4/fprintcolor.h
@@ -1,8 +1,20 @@
 #include <stdarg.h>
+#include "stmimpl.h"
 
 
-#define fprintf threadcolor_fprintf
+void stm_fatalerror(const char *format, ...)
+     __attribute__((format (printf, 1, 2), noreturn));
 
 
-int threadcolor_fprintf(FILE *stream, const char *format, ...)
-     __attribute__((format (printf, 2, 3)));
+#ifdef _GC_DEBUG
+
+#define dprintf(args)   threadcolor_printf args
+
+int threadcolor_printf(const char *format, ...)
+     __attribute__((format (printf, 1, 2)));
+
+#else
+
+#define dprintf(args)   do { } while(0)
+
+#endif
diff --git a/c4/gcpage.c b/c4/gcpage.c
--- a/c4/gcpage.c
+++ b/c4/gcpage.c
@@ -101,8 +101,7 @@
     /* Allocate and return a new page for the given size_class. */
     page_header_t *page = (page_header_t *)stm_malloc(GC_PAGE_SIZE);
     if (!page) {
-        fprintf(stderr, "allocate_new_page: out of memory!\n");
-        abort();
+        stm_fatalerror("allocate_new_page: out of memory!\n");
     }
     struct tx_public_descriptor *gcp = LOCAL_GCPAGES();
     gcp->count_pages++;
@@ -155,8 +154,7 @@
         return result;
     }
     else {
-        fprintf(stderr, "XXX stmgcpage_malloc: too big!\n");
-        abort();
+        stm_fatalerror("XXX stmgcpage_malloc: too big!\n");
     }
 }
 
@@ -178,8 +176,7 @@
         //stm_dbgmem_not_used(obj, size_class * WORD, 0);
     }
     else {
-        fprintf(stderr, "XXX stmgcpage_free: too big!\n");
-        abort();
+        stm_fatalerror("XXX stmgcpage_free: too big!\n");
     }
 }
 
@@ -196,7 +193,7 @@
 
  restart:
     if (obj->h_tid & GCFLAG_VISITED) {
-        fprintf(stderr, "[already visited: %p]\n", obj);
+        dprintf(("[already visited: %p]\n", obj));
         assert(obj == *pobj);
         assert((obj->h_revision & 3) ||   /* either odd, or stub */
                (obj->h_tid & GCFLAG_PRIVATE_FROM_PROTECTED));
@@ -301,7 +298,8 @@
     while (root != end) {
         gcptr o = *root;
         visit(root);
-        fprintf(stderr, "visit stack root: %p -> %p\n", o, *root);
+        dprintf(("visit stack root: %p -> %p\n", o, *root));
+        (void)o;   /* silence "warning: unused variable 'o'" */
         root++;
     }
 }
@@ -396,9 +394,8 @@
         revision_t v = obj->h_revision;
         if (IS_POINTER(v)) {
             /* has a more recent revision.  Oups. */
-            fprintf(stderr,
-                    "ABRT_COLLECT_MAJOR %p: %p was read but modified already\n",
-                    d, obj);
+            dprintf(("ABRT_COLLECT_MAJOR %p: "
+                     "%p was read but modified already\n", d, obj));
             AbortTransactionAfterCollect(d, ABRT_COLLECT_MAJOR);
             return;
         }
@@ -429,7 +426,7 @@
      */
     wlog_t *item;
 
-    fprintf(stderr, "fix public_to_private on thread %p\n", d);
+    dprintf(("fix public_to_private on thread %p\n", d));
 
     G2L_LOOP_FORWARD(d->public_to_private, item) {
 
@@ -440,7 +437,7 @@
                (item->val->h_tid & GCFLAG_PRIVATE_FROM_PROTECTED));
 
         item->addr->h_tid |= GCFLAG_PUBLIC_TO_PRIVATE;
-        fprintf(stderr, "\tpublic_to_private: %p\n", item->addr);
+        dprintf(("\tpublic_to_private: %p\n", item->addr));
 
     } G2L_LOOP_END;
 }
@@ -488,7 +485,7 @@
                 else {
 #ifdef DUMP_EXTRA
                     if (p->h_tid != DEBUG_WORD(0xDD)) {
-                        fprintf(stderr, "| freeing %p\n", p);
+                        dprintf(("| freeing %p\n", p));
                     }
 #endif
                     /* skip the assignment if compiled without asserts */
@@ -509,7 +506,7 @@
             for (j = 0; j < objs_per_page; j++) {
                 assert(!(p->h_tid & GCFLAG_VISITED));
                 if (p->h_tid != DEBUG_WORD(0xDD)) {
-                    fprintf(stderr, "| freeing %p (with page %p)\n", p, lpage);
+                    dprintf(("| freeing %p (with page %p)\n", p, lpage));
                 }
                 p = (gcptr)(((char *)p) + obj_size);
             }
@@ -643,7 +640,7 @@
 static void major_collect(void)
 {
     stmgcpage_acquire_global_lock();
-    fprintf(stderr, ",-----\n| running major collection...\n");
+    dprintf((",-----\n| running major collection...\n"));
 
     force_minor_collections();
 
@@ -662,10 +659,10 @@
     free_closed_thread_descriptors();
     update_next_threshold();
 
-    fprintf(stderr, "| %lu bytes alive, %lu not used, countdown %lu\n`-----\n",
-            (unsigned long)mc_total_in_use,
-            (unsigned long)(mc_total_reserved - mc_total_in_use),
-            (unsigned long)countdown_next_major_coll);
+    dprintf(("| %lu bytes alive, %lu not used, countdown %lu\n`-----\n",
+             (unsigned long)mc_total_in_use,
+             (unsigned long)(mc_total_reserved - mc_total_in_use),
+             (unsigned long)countdown_next_major_coll));
     stmgcpage_release_global_lock();
 }
 
diff --git a/c4/nursery.c b/c4/nursery.c
--- a/c4/nursery.c
+++ b/c4/nursery.c
@@ -18,8 +18,8 @@
     d->nursery_end = d->nursery_base + GC_NURSERY;
     d->nursery_current = d->nursery_base;
 
-    fprintf(stderr, "minor: nursery is at [%p to %p]\n", d->nursery_base,
-            d->nursery_end);
+    dprintf(("minor: nursery is at [%p to %p]\n", d->nursery_base,
+             d->nursery_end));
 }
 
 void stmgc_done_nursery(void)
@@ -155,8 +155,8 @@
             return mangle_hash((revision_t)p);
         }
 
-        fprintf(stderr, "stm_id(%p) has orig fst: %p\n", 
-                p, (gcptr)p->h_original);
+        dprintf(("stm_id(%p) has orig fst: %p\n", 
+                 p, (gcptr)p->h_original));
         return mangle_hash(p->h_original);
     } 
     else if (!(p->h_tid & GCFLAG_PRIVATE_FROM_PROTECTED)
@@ -170,7 +170,7 @@
            old at the same time, and we see the OLD flag 
            before h_original has been set.
         */
-        fprintf(stderr, "stm_id(%p) is old, orig=0 fst: %p\n", p, p);
+        dprintf(("stm_id(%p) is old, orig=0 fst: %p\n", p, p));
         return mangle_hash((revision_t)p);
     }
     
@@ -185,13 +185,13 @@
     */
     if (p->h_original) { /* maybe now? */
         result = p->h_original;
-        fprintf(stderr, "stm_id(%p) has orig: %p\n", 
-                p, (gcptr)p->h_original);
+        dprintf(("stm_id(%p) has orig: %p\n", 
+                 p, (gcptr)p->h_original));
     }
     else if (p->h_tid & GCFLAG_OLD) {
         /* it must be this exact object */
         result = (revision_t)p;
-        fprintf(stderr, "stm_id(%p) is old, orig=0: %p\n", p, p);
+        dprintf(("stm_id(%p) is old, orig=0: %p\n", p, p));
     }
     else {
         /* must create shadow original object or use
@@ -203,8 +203,8 @@
             // B->h_tid |= GCFLAG_PUBLIC; done by CommitPrivateFromProtected
             
             result = (revision_t)B;
-            fprintf(stderr, "stm_id(%p) young, pfp, use backup %p\n", 
-                    p, (gcptr)p->h_original);
+            dprintf(("stm_id(%p) young, pfp, use backup %p\n", 
+                     p, (gcptr)p->h_original));
         }
         else {
             gcptr O = stmgc_duplicate_old(p);
@@ -213,7 +213,7 @@
             O->h_tid |= GCFLAG_PUBLIC;
             
             result = (revision_t)O;
-            fprintf(stderr, "stm_id(%p) young, make shadow %p\n", p, O); 
+            dprintf(("stm_id(%p) young, make shadow %p\n", p, O));
         }
     }
     
@@ -242,7 +242,7 @@
 
     gcptr fresh_old_copy = stmgc_duplicate_old(obj);
 
-    fprintf(stderr, "minor: %p is copied to %p\n", obj, fresh_old_copy);
+    dprintf(("minor: %p is copied to %p\n", obj, fresh_old_copy));
     return fresh_old_copy;
 }
 
@@ -255,7 +255,7 @@
     memcpy(id, obj, size);
     id->h_tid &= ~GCFLAG_HAS_ID;
     id->h_tid |= GCFLAG_OLD;
-    fprintf(stderr, "copy_to_old_id_copy(%p -> %p)\n", obj, id);
+    dprintf(("copy_to_old_id_copy(%p -> %p)\n", obj, id));
 }
 
 static void visit_if_young(gcptr *root)
@@ -340,7 +340,7 @@
            in the past, but someone made even more changes.
            Nothing to do now.
         */
-        fprintf(stderr, "trace_stub: %p not a stub, ignored\n", S);
+        dprintf(("trace_stub: %p not a stub, ignored\n", S));
         return;
     }
 
@@ -349,7 +349,7 @@
         /* Bah, it's indeed a stub but for another thread.  Nothing
            to do now.
         */
-        fprintf(stderr, "trace_stub: %p stub wrong thread, ignored\n", S);
+        dprintf(("trace_stub: %p stub wrong thread, ignored\n", S));
         return;
     }
 
@@ -357,7 +357,7 @@
        feet because we hold our own collection_lock.
     */
     gcptr L = (gcptr)(w - 2);
-    fprintf(stderr, "trace_stub: %p stub -> %p\n", S, L);
+    dprintf(("trace_stub: %p stub -> %p\n", S, L));
     visit_if_young(&L);
     assert(S->h_tid & GCFLAG_STUB);
     S->h_revision = ((revision_t)L) | 2;
@@ -404,14 +404,14 @@
                We are in a case where we know the transaction will not
                be able to commit successfully.
             */
-            fprintf(stderr, "public_to_young: %p was modified! abort!\n", P);
+            dprintf(("public_to_young: %p was modified! abort!\n", P));
             item->val = NULL;
             AbortTransactionAfterCollect(d, ABRT_COLLECT_MINOR);
             continue;
         }
 
-        fprintf(stderr, "public_to_young: %p -> %p in public_to_private\n",
-                item->addr, item->val);
+        dprintf(("public_to_young: %p -> %p in public_to_private\n",
+                 item->addr, item->val));
         assert(_stm_is_private(item->val));
         visit_if_young(&item->val);
         continue;
@@ -422,11 +422,11 @@
                It must come from an older transaction that aborted.
                Nothing to do now.
             */
-            fprintf(stderr, "public_to_young: %p ignored\n", P);
+            dprintf(("public_to_young: %p ignored\n", P));
             continue;
         }
 
-        fprintf(stderr, "public_to_young: %p -> ", P);
+        dprintf(("public_to_young: %p -> ", P));
         trace_stub(d, (gcptr)v);
     }
 
@@ -495,8 +495,8 @@
 
 static void minor_collect(struct tx_descriptor *d)
 {
-    fprintf(stderr, "minor collection [%p to %p]\n",
-            d->nursery_base, d->nursery_end);
+    dprintf(("minor collection [%p to %p]\n",
+             d->nursery_base, d->nursery_end));
 
     /* acquire the "collection lock" first */
     setup_minor_collect(d);
@@ -527,8 +527,8 @@
     d->nursery_base = stm_malloc(GC_NURSERY);
     memset(d->nursery_base, 0, GC_NURSERY);
     d->nursery_end = d->nursery_base + GC_NURSERY;
-    fprintf(stderr, "minor: nursery moved to [%p to %p]\n", d->nursery_base,
-            d->nursery_end);
+    dprintf(("minor: nursery moved to [%p to %p]\n", d->nursery_base,
+             d->nursery_end));
 #else
     memset(d->nursery_base, 0, GC_NURSERY);
 #endif
diff --git a/c4/steal.c b/c4/steal.c
--- a/c4/steal.c
+++ b/c4/steal.c
@@ -63,7 +63,7 @@
 
  done:
     *pobj = stub;
-    fprintf(stderr, "  stolen: fixing *%p: %p -> %p\n", pobj, obj, stub);
+    dprintf(("  stolen: fixing *%p: %p -> %p\n", pobj, obj, stub));
 }
 
 void stm_steal_stub(gcptr P)
@@ -120,7 +120,7 @@
         if (B->h_tid & GCFLAG_PUBLIC_TO_PRIVATE) {
             /* already stolen */
             assert(B->h_tid & GCFLAG_PUBLIC);
-            fprintf(stderr, "already stolen: %p -> %p <-> %p\n", P, L, B);
+            dprintf(("already stolen: %p -> %p <-> %p\n", P, L, B));
             L = B;
             goto already_stolen;
         }
@@ -130,13 +130,13 @@
            don't want to walk over the feet of the foreign thread
         */
         gcptrlist_insert2(&foreign_pd->stolen_objects, B, L);
-        fprintf(stderr, "stolen: %p -> %p <-> %p\n", P, L, B);
+        dprintf(("stolen: %p -> %p <-> %p\n", P, L, B));
         L = B;
     }
     else {
         if (L->h_tid & GCFLAG_PUBLIC) {
             /* already stolen */
-            fprintf(stderr, "already stolen: %p -> %p\n", P, L);
+            dprintf(("already stolen: %p -> %p\n", P, L));
 
             /* note that we should follow h_revision at least one more
                step: it is necessary if L is public but young (and then
@@ -145,12 +145,12 @@
             v = ACCESS_ONCE(L->h_revision);
             if (IS_POINTER(v)) {
                 L = (gcptr)v;
-                fprintf(stderr, "\t---> %p\n", L);
+                dprintf(("\t---> %p\n", L));
             }
             goto already_stolen;
         }
 
-        fprintf(stderr, "stolen: %p -> %p\n", P, L);
+        dprintf(("stolen: %p -> %p\n", P, L));
 
         
         if (!(L->h_tid & GCFLAG_OLD)) { 
@@ -182,7 +182,7 @@
                L. */
             gcptrlist_insert2(&foreign_pd->stolen_objects, L, NULL);
             L = O;
-            fprintf(stderr, "\t---> %p\n", L);
+            dprintf(("\t---> %p\n", L));
         }
 
         assert(L->h_tid & GCFLAG_OLD);
@@ -261,7 +261,7 @@
 
         /* this is definitely needed: all keys in public_to_private
            must appear in list_of_read_objects */
-        fprintf(stderr, "n.readobj: %p -> %p\n", B, L);
+        dprintf(("n.readobj: %p -> %p\n", B, L));
         assert(!(B->h_tid & GCFLAG_STUB));
         gcptrlist_insert(&d->list_of_read_objects, B);
 
diff --git a/c4/stmsync.c b/c4/stmsync.c
--- a/c4/stmsync.c
+++ b/c4/stmsync.c
@@ -31,8 +31,7 @@
     struct tx_descriptor *d = thread_descriptor;
     d->shadowstack = malloc(sizeof(gcptr) * LENGTH_SHADOW_STACK);
     if (!d->shadowstack) {
-        fprintf(stderr, "out of memory: shadowstack\n");
-        abort();
+        stm_fatalerror("out of memory: shadowstack\n");
     }
     stm_shadowstack = d->shadowstack;
     d->shadowstack_end_ref = &stm_shadowstack;
@@ -78,7 +77,7 @@
 gcptr stm_read_barrier(gcptr obj)
 {
     //if (FXCACHE_AT(obj) == obj)
-    //    fprintf(stderr, "read_barrier: in cache: %p\n", obj);
+    //    dprintf(("read_barrier: in cache: %p\n", obj));
 
     /* XXX inline in the caller, optimize to get the smallest code */
     if (UNLIKELY((obj->h_revision != stm_private_rev_num) &&
@@ -230,12 +229,12 @@
     int err = pthread_rwlock_rdlock(&rwlock_shared);
     assert(err == 0);
     //assert(stmgc_nursery_hiding(thread_descriptor, 0));
-    fprintf(stderr, "stm_start_sharedlock\n");
+    dprintf(("stm_start_sharedlock\n"));
 }
 
 void stm_stop_sharedlock(void)
 {
-    fprintf(stderr, "stm_stop_sharedlock\n");
+    dprintf(("stm_stop_sharedlock\n"));
     //assert(stmgc_nursery_hiding(thread_descriptor, 1));
     int err = pthread_rwlock_unlock(&rwlock_shared);
     assert(err == 0);
@@ -245,12 +244,12 @@
 {
     int err = pthread_rwlock_wrlock(&rwlock_shared);
     assert(err == 0);
-    fprintf(stderr, "start_exclusivelock\n");
+    dprintf(("start_exclusivelock\n"));
 }
 
 static void stop_exclusivelock(void)
 {
-    fprintf(stderr, "stop_exclusivelock\n");
+    dprintf(("stop_exclusivelock\n"));
     int err = pthread_rwlock_unlock(&rwlock_shared);
     assert(err == 0);
 }
@@ -317,10 +316,10 @@
 
 void stm_clear_between_tests(void)
 {
-    fprintf(stderr, "\n"
+    dprintf(("\n"
             "===============================================================\n"
             "========================[  START  ]============================\n"
             "===============================================================\n"
-            "\n");
+            "\n"));
     gcptrlist_clear(&stm_prebuilt_gcroots);
 }


More information about the pypy-commit mailing list