Implement nursery allocation tracking.

	* sgen-nursery-allocator.c: Add lighweight logging of
	all nursery operations done by the allocator and have
	functions that spill the data. This is very helpfull to
	debug and analyse nursery related issues.

diff --git a/mono/metadata/sgen-nursery-allocator.c b/mono/metadata/sgen-nursery-allocator.c
index 9f3d2b55f9d3a57bd3cd89ce84317299ad9eda35..f739e5a4222e1b9e05df8a182625d07b4f08a45d 100644 (file)
--- a/mono/metadata/sgen-nursery-allocator.c
+++ b/mono/metadata/sgen-nursery-allocator.c
@@ -87,6 +87,7 @@ cleanup the code that readies the nursery for pinning/collection
 #include "utils/mono-semaphore.h"
 #include "utils/mono-counters.h"
 #include "utils/mono-proclib.h"
+#include "utils/mono-threads.h"
 
 
 typedef struct _Fragment Fragment;
@@ -105,6 +106,10 @@ struct _Fragment {
 /*How much space is tolerable to be wasted from the current fragment when allocating a new TLAB*/
 #define MAX_NURSERY_TLAB_WASTE 512
 
+/* Enable it so nursery allocation diagnostic data is collected */
+//#define NALLOC_DEBUG 1
+
+
 /* fragments that are free and ready to be used for allocation */
 static Fragment *nursery_fragments = NULL;
 /* freeelist of fragment structures */
@@ -124,6 +129,124 @@ static long long stat_wasted_fragments_bytes = 0;
 
 #endif
 
+/************************************Nursery allocation debugging *********************************************/
+
+#ifdef NALLOC_DEBUG
+
+enum {
+       FIXED_ALLOC = 1,
+       RANGE_ALLOC,
+       PINNING,
+       BLOCK_ZEROING,
+       CLEAR_NURSERY_FRAGS
+};
+
+typedef struct {
+       char *address;
+       size_t size;
+       int reason;
+       int seq;
+       MonoNativeThreadId tid;
+} AllocRecord;
+
+#define ALLOC_RECORD_COUNT 128000
+
+
+static AllocRecord *alloc_records;
+static volatile int next_record;
+static volatile int alloc_count;
+
+
+static const char*
+get_reason_name (AllocRecord *rec)
+{
+       switch (rec->reason) {
+       case FIXED_ALLOC: return "fixed-alloc";
+       case RANGE_ALLOC: return "range-alloc";
+       case PINNING: return "pinning";
+       case BLOCK_ZEROING: return "block-zeroing";
+       case CLEAR_NURSERY_FRAGS: return "clear-nursery-frag";
+       default: return "invalid";
+       }
+}
+
+static void
+reset_alloc_records (void)
+{
+       next_record = 0;
+       alloc_count = 0;
+}
+
+static void
+add_alloc_record (char *addr, size_t size, int reason)
+{
+       int idx = InterlockedIncrement (&next_record) - 1;
+       alloc_records [idx].address = addr;
+       alloc_records [idx].size = size;
+       alloc_records [idx].reason = reason;
+       alloc_records [idx].seq = idx;
+       alloc_records [idx].tid = mono_native_thread_id_get ();
+}
+
+static int
+comp_alloc_record (const void *_a, const void *_b)
+{
+       const AllocRecord *a = _a;
+       const AllocRecord *b = _b;
+       if (a->address == b->address)
+               return a->seq - b->seq;
+       return a->address - b->address;
+}
+
+#define rec_end(REC) ((REC)->address + (REC)->size)
+
+void
+dump_alloc_records (void)
+{
+       int i;
+       qsort (alloc_records, next_record, sizeof (AllocRecord), comp_alloc_record);
+
+       printf ("------------------------------------DUMP RECORDS----------------------------\n");
+       for (i = 0; i < next_record; ++i) {
+               AllocRecord *rec = alloc_records + i;
+               printf ("obj [%p, %p] size %zd reason %s seq %d %zx\n", rec->address, rec_end (rec), rec->size, get_reason_name (rec), rec->seq, (gsize)rec->tid);
+       }
+}
+
+void
+verify_alloc_records (void)
+{
+       int i;
+       int total = 0;
+       int holes = 0;
+       int max_hole = 0;
+       AllocRecord *prev = NULL;
+
+       qsort (alloc_records, next_record, sizeof (AllocRecord), comp_alloc_record);
+       printf ("------------------------------------DUMP RECORDS- %d %d---------------------------\n", next_record, alloc_count);
+       for (i = 0; i < next_record; ++i) {
+               AllocRecord *rec = alloc_records + i;
+               int hole_size = 0;
+               total += rec->size;
+               if (prev) {
+                       if (rec_end (prev) > rec->address)
+                               printf ("WE GOT OVERLAPPING objects %p and %p\n", prev->address, rec->address);
+                       if ((rec->address - rec_end (prev)) >= 8)
+                               ++holes;
+                       hole_size = rec->address - rec_end (prev);
+                       max_hole = MAX (max_hole, hole_size);
+               }
+               printf ("obj [%p, %p] size %zd hole to prev %d\n", rec->address, rec_end (rec), rec->size, hole_size);
+               prev = rec;
+       }
+       printf ("SUMMARY total alloc'd %d holes %d max_hole %d\n", total, holes, max_hole);
+}
+
+#endif
+
+/*********************************************************************************/
+
+
 static inline gpointer
 mask (gpointer n, uintptr_t bit)
 {
@@ -254,6 +377,9 @@ alloc_from_fragment (Fragment *frag, size_t size)
                if (mono_sgen_get_nursery_clear_policy () == CLEAR_AT_TLAB_CREATION && claim_remaining_size (frag, end)) {
                        /* Clear the remaining space, pinning depends on this. FIXME move this to use phony arrays */
                        memset (end, 0, frag->fragment_end - end);
+#ifdef NALLOC_DEBUG
+                       add_alloc_record (end, frag->fragment_end - end, BLOCK_ZEROING);
+#endif
                }
 
                prev_ptr = find_previous_pointer_fragment (frag);
@@ -313,6 +439,9 @@ mono_sgen_clear_nursery_fragments (void)
                for (frag = unmask (nursery_fragments); frag; frag = unmask (frag->next)) {
                        DEBUG (4, fprintf (gc_debug_file, "Clear nursery frag %p-%p\n", frag->fragment_next, frag->fragment_end));
                        memset (frag->fragment_next, 0, frag->fragment_end - frag->fragment_next);
+#ifdef NALLOC_DEBUG
+                       add_alloc_record (frag->fragment_next, frag->fragment_end - frag->fragment_next, CLEAR_NURSERY_FRAGS);
+#endif
                }
        }
 }
@@ -363,6 +492,11 @@ add_nursery_frag (size_t frag_size, char* frag_start, char* frag_end)
                if (mono_sgen_get_nursery_clear_policy () == CLEAR_AT_GC)
                        memset (frag_start, 0, frag_size);
 
+#ifdef NALLOC_DEBUG
+               /* XXX convert this into a flight record entry
+               printf ("\tfragment [%p %p] size %zd\n", frag_start, frag_end, frag_size);
+               */
+#endif
                add_fragment (frag_start, frag_end);
                fragment_total += frag_size;
        } else {
@@ -372,7 +506,6 @@ add_nursery_frag (size_t frag_size, char* frag_start, char* frag_end)
        }
 }
 
-
 mword
 mono_sgen_build_nursery_fragments (GCMemSection *nursery_section, void **start, int num_entries)
 {
@@ -380,6 +513,10 @@ mono_sgen_build_nursery_fragments (GCMemSection *nursery_section, void **start,
        size_t frag_size;
        int i;
 
+#ifdef NALLOC_DEBUG
+       reset_alloc_records ();
+#endif
+
        while (unmask (nursery_fragments)) {
                Fragment *nf = unmask (nursery_fragments);
                Fragment *next = unmask (nf->next);
@@ -401,6 +538,9 @@ mono_sgen_build_nursery_fragments (GCMemSection *nursery_section, void **start,
                if (frag_size)
                        add_nursery_frag (frag_size, frag_start, frag_end);
                frag_size = SGEN_ALIGN_UP (mono_sgen_safe_object_get_size ((MonoObject*)start [i]));
+#ifdef NALLOC_DEBUG
+               add_alloc_record (start [i], frag_size, PINNING);
+#endif
                frag_start = (char*)start [i] + frag_size;
        }
        nursery_last_pinned_end = frag_start;
@@ -437,6 +577,7 @@ gboolean
 mono_sgen_can_alloc_size (size_t size)
 {
        Fragment *frag;
+       size = SGEN_ALIGN_UP (size);
 
        for (frag = unmask (nursery_fragments); frag; frag = unmask (frag->next)) {
                if ((frag->fragment_end - frag->fragment_next) >= size)
@@ -450,6 +591,11 @@ mono_sgen_nursery_alloc (size_t size)
 {
        Fragment *frag;
        DEBUG (4, fprintf (gc_debug_file, "Searching nursery for size: %zd\n", size));
+       size = SGEN_ALIGN_UP (size);
+
+#ifdef NALLOC_DEBUG
+       InterlockedIncrement (&alloc_count);
+#endif
 
 restart:
        for (frag = unmask (nursery_fragments); frag; frag = unmask (frag->next)) {
@@ -457,7 +603,10 @@ restart:
                        void *p = alloc_from_fragment (frag, size);
                        if (!p)
                                goto restart;
-                       return p;               
+#ifdef NALLOC_DEBUG
+                       add_alloc_record (p, size, FIXED_ALLOC);
+#endif
+                       return p;
                }
        }
        return NULL;
@@ -471,6 +620,10 @@ mono_sgen_nursery_alloc_range (size_t desired_size, size_t minimum_size, int *ou
 restart:
        min_frag = NULL;
 
+#ifdef NALLOC_DEBUG
+       InterlockedIncrement (&alloc_count);
+#endif
+
        for (frag = unmask (nursery_fragments); frag; frag = unmask (frag->next)) {
                int frag_size = frag->fragment_end - frag->fragment_next;
                if (desired_size <= frag_size) {
@@ -480,6 +633,9 @@ restart:
                        p = alloc_from_fragment (frag, desired_size);
                        if (!p)
                                goto restart;
+#ifdef NALLOC_DEBUG
+                       add_alloc_record (p, desired_size, RANGE_ALLOC);
+#endif
                        return p;
                }
                if (minimum_size <= frag_size)
@@ -508,6 +664,9 @@ restart:
                /*XXX restarting here is quite dubious given this is already second chance allocation. */
                if (!p)
                        goto restart;
+#ifdef NALLOC_DEBUG
+               add_alloc_record (p, frag_size, RANGE_ALLOC);
+#endif
                return p;
        }
 
@@ -531,6 +690,9 @@ void
 mono_sgen_init_nursery_allocator (void)
 {
        mono_sgen_register_fixed_internal_mem_type (INTERNAL_MEM_FRAGMENT, sizeof (Fragment));
+#ifdef NALLOC_DEBUG
+       alloc_records = mono_sgen_alloc_os_memory (sizeof (AllocRecord) * ALLOC_RECORD_COUNT, TRUE);
+#endif
 }
 
 void