Add some more debugging + asserts

From the course of debugging this gc issue.  this commit
shouldn't have much effect normally.

src/gc/collector.cpp

@@ -372,15 +372,6 @@ static void markPhase() {
     VALGRIND_DISABLE_ERROR_REPORTING;
 #endif
 
-#if TRACE_GC_MARKING
-#if 1 // separate log file per collection
-    char tracefn_buf[80];
-    snprintf(tracefn_buf, sizeof(tracefn_buf), "gc_trace_%03d.txt", ncollections);
-    trace_fp = fopen(tracefn_buf, "w");
-#else // overwrite previous log file with each collection
-    trace_fp = fopen("gc_trace.txt", "w");
-#endif
-#endif
     GC_TRACE_LOG("Starting collection %d\n", ncollections);
 
     GC_TRACE_LOG("Looking at roots\n");
@@ -420,11 +411,6 @@ static void markPhase() {
         class_objects.insert(cls->cls);
     }
 
-#if TRACE_GC_MARKING
-    fclose(trace_fp);
-    trace_fp = NULL;
-#endif
-
 #ifndef NVALGRIND
     VALGRIND_ENABLE_ERROR_REPORTING;
 #endif
@@ -490,6 +476,16 @@ void runCollection() {
 
     Timer _t("collecting", /*min_usec=*/10000);
 
+#if TRACE_GC_MARKING
+#if 1 // separate log file per collection
+    char tracefn_buf[80];
+    snprintf(tracefn_buf, sizeof(tracefn_buf), "gc_trace_%d.%03d.txt", getpid(), ncollections);
+    trace_fp = fopen(tracefn_buf, "w");
+#else // overwrite previous log file with each collection
+    trace_fp = fopen("gc_trace.txt", "w");
+#endif
+#endif
+
     global_heap.prepareForCollection();
 
     markPhase();
@@ -527,6 +523,11 @@ void runCollection() {
         global_heap.free(GCAllocation::fromUserData(o));
     }
 
+#if TRACE_GC_MARKING
+    fclose(trace_fp);
+    trace_fp = NULL;
+#endif
+
     should_not_reenter_gc = false; // end non-reentrant section
 
     while (!weak_references.empty()) {

src/gc/heap.cpp

@@ -456,6 +456,7 @@ SmallArena::Block** SmallArena::_freeChain(Block** head, std::vector<Box*>& weak
                 clearMark(al);
             } else {
                 if (_doFree(al, &weakly_referenced)) {
+                    GC_TRACE_LOG("freeing %p\n", al->user_data);
                     b->isfree.set(atom_idx);
 #ifndef NDEBUG
                     memset(al->user_data, 0xbb, b->size - sizeof(GCAllocation));

src/runtime/iterators.cpp

@@ -42,9 +42,10 @@ public:
         STAT_TIMER(t0, "us_timer_iteratorgeneric_next", 0);
 
         Box* next = PyIter_Next(iterator);
-        if (next)
+        if (next) {
+            assert(gc::isValidGCObject(next));
             value = next;
-        else {
+        } else {
             checkAndThrowCAPIException();
             *this = *end();
         }
@@ -91,7 +92,11 @@ public:
         }
     }
 
-    Box* getValue() override { return getValue(obj, index); }
+    Box* getValue() override {
+        Box* r = getValue(obj, index);
+        assert(gc::isValidGCObject(r));
+        return r;
+    }
 
     bool isSame(const BoxIteratorImpl* _rhs) override {
         const auto rhs = (const BoxIteratorIndex*)_rhs;

src/runtime/objmodel.cpp

@@ -569,8 +569,8 @@ HiddenClass* HiddenClass::getOrMakeChild(BoxedString* attr) {
     num_hclses.log();
 
     HiddenClass* rtn = new HiddenClass(this);
-    this->children[attr] = rtn;
     rtn->attr_offsets[attr] = this->attributeArraySize();
+    this->children[attr] = rtn;
     assert(rtn->attributeArraySize() == this->attributeArraySize() + 1);
     return rtn;
 }
@@ -580,9 +580,10 @@ HiddenClass* HiddenClass::getAttrwrapperChild() {
     assert(attrwrapper_offset == -1);
 
     if (!attrwrapper_child) {
-        attrwrapper_child = new HiddenClass(this);
-        attrwrapper_child->attrwrapper_offset = this->attributeArraySize();
-        assert(attrwrapper_child->attributeArraySize() == this->attributeArraySize() + 1);
+        HiddenClass* made = new HiddenClass(this);
+        made->attrwrapper_offset = this->attributeArraySize();
+        this->attrwrapper_child = made;
+        assert(made->attributeArraySize() == this->attributeArraySize() + 1);
     }
 
     return attrwrapper_child;

src/runtime/stacktrace.cpp

@@ -135,7 +135,16 @@ extern "C" void abort() {
     }
 
     if (PAUSE_AT_ABORT) {
-        printf("PID %d about to call libc abort; pausing for a debugger...\n", getpid());
+        fprintf(stderr, "PID %d about to call libc abort; pausing for a debugger...\n", getpid());
+
+        // Sometimes stderr isn't available (or doesn't immediately appear), so write out a file
+        // just in case:
+        FILE* f = fopen("pausing.txt", "w");
+        if (f) {
+            fprintf(f, "PID %d about to call libc abort; pausing for a debugger...\n", getpid());
+            fclose(f);
+        }
+
         while (true) {
             sleep(1);
         }

src/runtime/tuple.cpp

@@ -31,6 +31,8 @@
 namespace pyston {
 
 extern "C" Box* createTuple(int64_t nelts, Box** elts) {
+    for (int i = 0; i < nelts; i++)
+        assert(gc::isValidGCObject(elts[i]));
     return BoxedTuple::create(nelts, elts);
 }
 

src/runtime/types.h

@@ -624,18 +624,24 @@ public:
     }
     static BoxedTuple* create(int64_t nelts, Box** elts) {
         BoxedTuple* rtn = new (nelts) BoxedTuple();
+        for (int i = 0; i < nelts; i++)
+            assert(gc::isValidGCObject(elts[i]));
         memmove(&rtn->elts[0], elts, sizeof(Box*) * nelts);
         return rtn;
     }
     static BoxedTuple* create1(Box* elt0) {
         BoxedTuple* rtn = new (1) BoxedTuple();
         rtn->elts[0] = elt0;
+        for (int i = 0; i < rtn->size(); i++)
+            assert(gc::isValidGCObject(rtn->elts[i]));
         return rtn;
     }
     static BoxedTuple* create2(Box* elt0, Box* elt1) {
         BoxedTuple* rtn = new (2) BoxedTuple();
         rtn->elts[0] = elt0;
         rtn->elts[1] = elt1;
+        for (int i = 0; i < rtn->size(); i++)
+            assert(gc::isValidGCObject(rtn->elts[i]));
         return rtn;
     }
     static BoxedTuple* create3(Box* elt0, Box* elt1, Box* elt2) {
@@ -643,6 +649,8 @@ public:
         rtn->elts[0] = elt0;
         rtn->elts[1] = elt1;
         rtn->elts[2] = elt2;
+        for (int i = 0; i < rtn->size(); i++)
+            assert(gc::isValidGCObject(rtn->elts[i]));
         return rtn;
     }
     static BoxedTuple* create4(Box* elt0, Box* elt1, Box* elt2, Box* elt3) {
@@ -651,6 +659,8 @@ public:
         rtn->elts[1] = elt1;
         rtn->elts[2] = elt2;
         rtn->elts[3] = elt3;
+        for (int i = 0; i < rtn->size(); i++)
+            assert(gc::isValidGCObject(rtn->elts[i]));
         return rtn;
     }
     static BoxedTuple* create5(Box* elt0, Box* elt1, Box* elt2, Box* elt3, Box* elt4) {
@@ -660,9 +670,17 @@ public:
         rtn->elts[2] = elt2;
         rtn->elts[3] = elt3;
         rtn->elts[4] = elt4;
+        for (int i = 0; i < rtn->size(); i++)
+            assert(gc::isValidGCObject(rtn->elts[i]));
+        return rtn;
+    }
+    static BoxedTuple* create(std::initializer_list<Box*> members) {
+        auto rtn = new (members.size()) BoxedTuple(members);
+
+        for (int i = 0; i < rtn->size(); i++)
+            assert(gc::isValidGCObject(rtn->elts[i]));
         return rtn;
     }
-    static BoxedTuple* create(std::initializer_list<Box*> members) { return new (members.size()) BoxedTuple(members); }
 
     static BoxedTuple* create(int64_t size, BoxedClass* cls) {
         BoxedTuple* rtn;
@@ -731,6 +749,7 @@ private:
         Box** p = &elts[0];
         for (auto b : members) {
             *p++ = b;
+            assert(gc::isValidGCObject(b));
         }
     }