Selectively compile debug traces

This commit is contained in:
Justin Ethier 2015-11-30 21:40:16 -05:00
parent e29633f2b2
commit 52f0868d24
3 changed files with 82 additions and 119 deletions

130
gc.c
View file

@ -88,9 +88,7 @@ gc_heap *gc_heap_create(size_t size, size_t max_size, size_t chunk_size)
h->size = size; h->size = size;
h->chunk_size = chunk_size; h->chunk_size = chunk_size;
h->max_size = max_size; h->max_size = max_size;
//printf("DEBUG h->data addr: %p\n", &(h->data));
h->data = (char *) gc_heap_align(sizeof(h->data) + (uint)&(h->data)); h->data = (char *) gc_heap_align(sizeof(h->data) + (uint)&(h->data));
//printf("DEBUG h->data addr: %p\n", h->data);
h->next = NULL; h->next = NULL;
free = h->free_list = (gc_free_list *)h->data; free = h->free_list = (gc_free_list *)h->data;
next = (gc_free_list *)(((char *) free) + gc_heap_align(gc_free_chunk_size)); next = (gc_free_list *)(((char *) free) + gc_heap_align(gc_free_chunk_size));
@ -99,6 +97,8 @@ gc_heap *gc_heap_create(size_t size, size_t max_size, size_t chunk_size)
next->size = size - gc_heap_align(gc_free_chunk_size); next->size = size - gc_heap_align(gc_free_chunk_size);
next->next = NULL; next->next = NULL;
#if GC_DEBUG_PRINTFS #if GC_DEBUG_PRINTFS
fprintf(stderr, "DEBUG h->data addr: %p\n", &(h->data));
fprintf(stderr, "DEBUG h->data addr: %p\n", h->data);
fprintf(stderr, ("heap: %p-%p data: %p-%p size: %d\n"), fprintf(stderr, ("heap: %p-%p data: %p-%p size: %d\n"),
h, ((char*)h)+gc_heap_pad_size(size), h->data, h->data + size, size); h, ((char*)h)+gc_heap_pad_size(size), h->data, h->data + size, size);
fprintf(stderr, ("first: %p end: %p\n"), fprintf(stderr, ("first: %p end: %p\n"),
@ -274,7 +274,9 @@ int gc_grow_heap(gc_heap *h, size_t size, size_t chunk_size)
h_new = gc_heap_create(new_size, h_last->max_size, chunk_size); h_new = gc_heap_create(new_size, h_last->max_size, chunk_size);
h_last->next = h_new; h_last->next = h_new;
pthread_mutex_unlock(&heap_lock); pthread_mutex_unlock(&heap_lock);
printf("DEBUG - grew heap\n"); #if GC_DEBUG_TRACE
printf("DEBUG - grew heap\n");
#endif
return (h_new != NULL); return (h_new != NULL);
} }
@ -342,30 +344,27 @@ void *gc_alloc(gc_heap *h, size_t size, char *obj, gc_thread_data *thd, int *hea
exit(1); // TODO: throw error??? exit(1); // TODO: throw error???
} }
} }
//#if GC_DEBUG_PRINTFS #if GC_DEBUG_TRACE
fprintf(stdout, "alloc %p size = %d, obj=%p, tag=%ld\n", result, size, obj, type_of(obj)); fprintf(stdout, "alloc %p size = %d, obj=%p, tag=%ld\n", result, size, obj, type_of(obj));
//Cyc_display(obj, stdout); //// TODO: Debug check, remove (ifdef it) once GC is stabilized
//fprintf(stdout, "\n"); //if (is_value_type(result)) {
//#endif // printf("Invalid allocated address - is a value type %p\n", result);
//}
// TODO: Debug check, remove (ifdef it) once GC is stabilized #endif
if (is_value_type(result)) {
printf("Invalid allocated address - is a value type %p\n", result);
}
return result; return result;
} }
size_t gc_allocated_bytes(object obj, gc_free_list *q, gc_free_list *r) size_t gc_allocated_bytes(object obj, gc_free_list *q, gc_free_list *r)
{ {
tag_type t; tag_type t;
#if GC_SAFETY_CHECKS
if (is_value_type(obj)) { if (is_value_type(obj)) {
fprintf(stdout, fprintf(stdout,
"gc_allocated_bytes - passed value type %p q=[%p, %d] r=[%p, %d]\n", "gc_allocated_bytes - passed value type %p q=[%p, %d] r=[%p, %d]\n",
obj, q, q->size, r, r->size); obj, q, q->size, r, r->size);
exit(1); exit(1);
//return gc_heap_align(1);
} }
#endif
t = type_of(obj); t = type_of(obj);
if (t == cons_tag) return gc_heap_align(sizeof(cons_type)); if (t == cons_tag) return gc_heap_align(sizeof(cons_type));
if (t == macro_tag) return gc_heap_align(sizeof(macro_type)); if (t == macro_tag) return gc_heap_align(sizeof(macro_type));
@ -388,10 +387,8 @@ size_t gc_allocated_bytes(object obj, gc_free_list *q, gc_free_list *r)
if (t == port_tag) return gc_heap_align(sizeof(port_type)); if (t == port_tag) return gc_heap_align(sizeof(port_type));
if (t == cvar_tag) return gc_heap_align(sizeof(cvar_type)); if (t == cvar_tag) return gc_heap_align(sizeof(cvar_type));
//#if GC_DEBUG_PRINTFS
fprintf(stderr, "gc_allocated_bytes: unexpected object %p of type %ld\n", obj, t); fprintf(stderr, "gc_allocated_bytes: unexpected object %p of type %ld\n", obj, t);
exit(1); exit(1);
//#endif
return 0; return 0;
} }
@ -473,7 +470,7 @@ size_t gc_sweep(gc_heap *h, size_t *sum_freed_ptr)
// //
pthread_mutex_lock(&heap_lock); pthread_mutex_lock(&heap_lock);
for (; h; h = h->next) { // All heaps for (; h; h = h->next) { // All heaps
#if GC_DEBUG_CONCISE_PRINTFS #if GC_DEBUG_TRACE
fprintf(stdout, "sweep heap %p, size = %d\n", h, h->size); fprintf(stdout, "sweep heap %p, size = %d\n", h, h->size);
#endif #endif
p = gc_heap_first_block(h); p = gc_heap_first_block(h);
@ -485,16 +482,14 @@ size_t gc_sweep(gc_heap *h, size_t *sum_freed_ptr)
if ((char *)r == (char *)p) { // this is a free block, skip it if ((char *)r == (char *)p) { // this is a free block, skip it
p = (object) (((char *)p) + r->size); p = (object) (((char *)p) + r->size);
//#if GC_DEBUG_PRINTFS #if GC_DEBUG_TRACE
fprintf(stdout, "skip free block %p size = %d\n", p, r->size); fprintf(stdout, "skip free block %p size = %d\n", p, r->size);
//#endif #endif
continue; continue;
} }
size = gc_heap_align(gc_allocated_bytes(p, q, r)); size = gc_heap_align(gc_allocated_bytes(p, q, r));
//fprintf(stdout, "check object %p, size = %d\n", p, size);
//#if GC_DEBUG_CONCISE_PRINTFS #if GC_SAFETY_CHECKS
// DEBUG
if (!is_object_type(p)) { if (!is_object_type(p)) {
fprintf(stderr, "sweep: invalid object at %p", p); fprintf(stderr, "sweep: invalid object at %p", p);
exit(1); exit(1);
@ -507,14 +502,12 @@ size_t gc_sweep(gc_heap *h, size_t *sum_freed_ptr)
fprintf(stderr, "sweep: bad size at %p + %d > %p", p, size, r); fprintf(stderr, "sweep: bad size at %p + %d > %p", p, size, r);
exit(1); exit(1);
} }
// END DEBUG #endif
//#endif
if (mark(p) == gc_color_clear) { if (mark(p) == gc_color_clear) {
//#if GC_DEBUG_PRINTFS #if GC_DEBUG_VERBOSE
//fprintf(stdout, "sweep: object is not marked %p\n", p); fprintf(stdout, "sweep is freeing unmarked obj: %p with tag %ld\n", p, type_of(p));
fprintf(stdout, "sweep is freeing obj: %p with tag %ld\n", p, type_of(p)); #endif
//#endif
mark(p) = gc_color_blue; // Needed? mark(p) = gc_color_blue; // Needed?
// free p // free p
sum_freed += size; sum_freed += size;
@ -549,9 +542,9 @@ size_t gc_sweep(gc_heap *h, size_t *sum_freed_ptr)
if (freed > max_freed) if (freed > max_freed)
max_freed = freed; max_freed = freed;
} else { } else {
#if GC_DEBUG_PRINTFS //#if GC_DEBUG_VERBOSE
// fprintf(stdout, "sweep: object is marked %p\n", p); // fprintf(stdout, "sweep: object is marked %p\n", p);
#endif //#endif
p = (object)(((char *)p) + size); p = (object)(((char *)p) + size);
} }
} }
@ -573,7 +566,7 @@ void gc_thr_grow_move_buffer(gc_thread_data *d)
} }
d->moveBuf = realloc(d->moveBuf, d->moveBufLen * sizeof(void *)); d->moveBuf = realloc(d->moveBuf, d->moveBufLen * sizeof(void *));
#if GC_DEBUG_CONCISE_PRINTFS #if GC_DEBUG_TRACE
printf("grew moveBuffer, len = %d\n", d->moveBufLen); printf("grew moveBuffer, len = %d\n", d->moveBufLen);
#endif #endif
} }
@ -713,16 +706,16 @@ void gc_stack_mark_gray(gc_thread_data *thd, object obj)
if (is_object_type(obj)) { if (is_object_type(obj)) {
color = mark(obj); color = mark(obj);
// TODO: no need to run this all the time. enclose in an "ifdef DEBUG" once #if GC_SAFETY_CHECKS
// the GC is stabilized if (check_overflow(low_limit, obj) &&
if (check_overflow(low_limit, obj) && check_overflow(obj, high_limit) &&
check_overflow(obj, high_limit) && color != gc_color_red){
color != gc_color_red){ printf("stack object has wrong color %d!\n", color);
printf("stack object has wrong color %d!\n", color); Cyc_display(obj, stdout);
Cyc_display(obj, stdout); printf("\n");
printf("\n"); exit(1);
exit(1); }
} #endif
if (color == gc_color_clear) { if (color == gc_color_clear) {
gc_mark_gray(thd, obj); gc_mark_gray(thd, obj);
} else if (color == gc_color_red) { } else if (color == gc_color_red) {
@ -808,11 +801,13 @@ void gc_mut_update(gc_thread_data *thd, object old_obj, object value)
//Cyc_display(old_obj, stdout); //Cyc_display(old_obj, stdout);
//printf("\n"); //printf("\n");
gc_mark_gray(thd, old_obj); gc_mark_gray(thd, old_obj);
#if GC_DEBUG_VERBOSE
if (is_object_type(old_obj)) { if (is_object_type(old_obj)) {
printf("added to mark buffer (trace) from write barrier %p:mark %d:", old_obj, mark(old_obj)); printf("added to mark buffer (trace) from write barrier %p:mark %d:", old_obj, mark(old_obj));
Cyc_display(old_obj, stdout); Cyc_display(old_obj, stdout);
printf("\n"); printf("\n");
} }
#endif
} }
// TODO: concerned there may be an issue here with a stack object // TODO: concerned there may be an issue here with a stack object
// having a 'tree' of references that contains heap objects. these // having a 'tree' of references that contains heap objects. these
@ -858,10 +853,14 @@ void gc_mut_cooperate(gc_thread_data *thd)
} }
else if (thd->gc_status == STATUS_SYNC2) { else if (thd->gc_status == STATUS_SYNC2) {
// Mark thread "roots" // Mark thread "roots"
#if GC_DEBUG_VERBOSE
printf("gc_cont %p\n", thd->gc_cont); printf("gc_cont %p\n", thd->gc_cont);
#endif
gc_mark_gray(thd, thd->gc_cont); gc_mark_gray(thd, thd->gc_cont);
for (i = 0; i < thd->gc_num_args; i++) { for (i = 0; i < thd->gc_num_args; i++) {
#if GC_DEBUG_VERBOSE
printf("gc_args[%d] %p\n", i, thd->gc_args[i]); printf("gc_args[%d] %p\n", i, thd->gc_args[i]);
#endif
gc_mark_gray(thd, thd->gc_args[i]); gc_mark_gray(thd, thd->gc_args[i]);
} }
thd->gc_alloc_color = ATOMIC_GET(&gc_color_mark); thd->gc_alloc_color = ATOMIC_GET(&gc_color_mark);
@ -931,18 +930,14 @@ void gc_collector_trace()
pthread_mutex_lock(&(m->lock)); pthread_mutex_lock(&(m->lock));
while (m->last_read < m->last_write) { while (m->last_read < m->last_write) {
clean = 0; clean = 0;
//TODO: I think there is an off-by-one error here. inspect last read/write. #if GC_DEBUG_VERBOSE
//is the code going one too many? per paper it is not, but based on printf("gc_mark_black mark buffer %p, last_read = %d last_write = %d\n",
//logs it looks like it is reading past end of buffer. (ie, errors always seem (m->mark_buffer)[m->last_read],
//to be on the last object traced, and checking the history, an object m->last_read, m->last_write);
//incorrectly marked at position X can be seen to have been stored at position #endif
//X in a previous collection.
printf("gc_mark_black mark buffer %p, last_read = %d last_write = %d\n",
(m->mark_buffer)[m->last_read],
m->last_read, m->last_write);
gc_mark_black((m->mark_buffer)[m->last_read]); gc_mark_black((m->mark_buffer)[m->last_read]);
gc_empty_collector_stack(); gc_empty_collector_stack();
(m->last_read)++; // Inc here to try to prevent off-by-one errors (m->last_read)++; // Inc here to prevent off-by-one error
} }
pthread_mutex_unlock(&(m->lock)); pthread_mutex_unlock(&(m->lock));
} }
@ -1013,11 +1008,14 @@ void gc_mark_black(object obj)
if (mark(obj) != gc_color_red) { if (mark(obj) != gc_color_red) {
// Only blacken objects on the heap // Only blacken objects on the heap
mark(obj) = markColor; mark(obj) = markColor;
printf("marked %p %d\n", obj, markColor);
} }
else { #if GC_DEBUG_VERBOSE
if (mark(obj) != gc_color_red) {
printf("marked %p %d\n", obj, markColor);
} else {
printf("not marking stack obj %p %d\n", obj, markColor); printf("not marking stack obj %p %d\n", obj, markColor);
} }
#endif
} }
} }
@ -1030,7 +1028,9 @@ void gc_collector_mark_gray(object parent, object obj)
// could lead to stack corruption. // could lead to stack corruption.
if (is_object_type(obj) && mark(obj) == gc_color_clear) { if (is_object_type(obj) && mark(obj) == gc_color_clear) {
mark_stack = vpbuffer_add(mark_stack, &mark_stack_len, mark_stack_i++, obj); mark_stack = vpbuffer_add(mark_stack, &mark_stack_len, mark_stack_i++, obj);
printf("mark gray parent = %p (%ld) obj = %p\n", parent, type_of(parent), obj); #if GC_DEBUG_VERBOSE
printf("mark gray parent = %p (%ld) obj = %p\n", parent, type_of(parent), obj);
#endif
} }
} }
@ -1096,9 +1096,9 @@ void gc_collector()
{ {
int old_clear, old_mark; int old_clear, old_mark;
size_t freed = 0, max_freed = 0, total_size; size_t freed = 0, max_freed = 0, total_size;
//#if GC_DEBUG_CONCISE_PRINTFS #if GC_DEBUG_TRACE
time_t sweep_start = time(NULL); time_t sweep_start = time(NULL);
//#endif #endif
// TODO: what kind of sync is required here? // TODO: what kind of sync is required here?
//clear : //clear :
@ -1108,7 +1108,9 @@ void gc_collector()
old_mark = ATOMIC_GET(&gc_color_mark); old_mark = ATOMIC_GET(&gc_color_mark);
while(!ATOMIC_SET_IF_EQ(&gc_color_clear, old_clear, old_mark)){} while(!ATOMIC_SET_IF_EQ(&gc_color_clear, old_clear, old_mark)){}
while(!ATOMIC_SET_IF_EQ(&gc_color_mark, old_mark, old_clear)){} while(!ATOMIC_SET_IF_EQ(&gc_color_mark, old_mark, old_clear)){}
printf("DEBUG - swap clear %d / mark %d\n", gc_color_clear, gc_color_mark); #if GC_DEBUG_TRACE
printf("DEBUG - swap clear %d / mark %d\n", gc_color_clear, gc_color_mark);
#endif
gc_handshake(STATUS_SYNC1); gc_handshake(STATUS_SYNC1);
//printf("DEBUG - after handshake sync 1\n"); //printf("DEBUG - after handshake sync 1\n");
//mark : //mark :
@ -1122,17 +1124,19 @@ printf("DEBUG - swap clear %d / mark %d\n", gc_color_clear, gc_color_mark);
//printf("DEBUG - after wait_handshake aync\n"); //printf("DEBUG - after wait_handshake aync\n");
//trace : //trace :
gc_collector_trace(); gc_collector_trace();
printf("DEBUG - after trace\n"); #if GC_DEBUG_TRACE
//debug_dump_globals(); printf("DEBUG - after trace\n");
//debug_dump_globals();
#endif
gc_stage = STAGE_SWEEPING; gc_stage = STAGE_SWEEPING;
// //
//sweep : //sweep :
max_freed = gc_sweep(gc_get_heap(), &freed); max_freed = gc_sweep(gc_get_heap(), &freed);
// TODO: grow heap if it is mostly full after collection?? // TODO: grow heap if it is mostly full after collection??
//#if GC_DEBUG_CONCISE_PRINTFS #if GC_DEBUG_TRACE
printf("sweep done, freed = %d, max_freed = %d, elapsed = %ld\n", printf("sweep done, freed = %d, max_freed = %d, elapsed = %ld\n",
freed, max_freed, time(NULL) - sweep_start); freed, max_freed, time(NULL) - sweep_start);
//#endif #endif
gc_stage = STAGE_RESTING; gc_stage = STAGE_RESTING;
} }

View file

@ -180,9 +180,13 @@ gc_heap *gc_get_heap();
//void gc_collector() //void gc_collector()
/* GC debugging flags */ /* GC debugging flags */
//#define DEBUG_GC 0 #define GC_DEBUG_TRACE 0
#define GC_DEBUG_PRINTFS 0 #define GC_DEBUG_VERBOSE 0
#define GC_DEBUG_CONCISE_PRINTFS 0
/* Additional runtime checking of the GC system.
This is here because these checks should not be
necessary if GC is working correctly. */
#define GC_SAFETY_CHECKS 1
/* Show diagnostic information for the GC when program terminates */ /* Show diagnostic information for the GC when program terminates */
#define DEBUG_SHOW_DIAG 0 #define DEBUG_SHOW_DIAG 0

View file

@ -2408,40 +2408,15 @@ void Cyc_start_thread(gc_thread_data *thd)
exit(0); exit(0);
} }
//// Collect garbage using mark&sweep algorithm
//// Note non-global roots should be marked prior to calling this function.
//size_t gc_collect(gc_heap *h, size_t *sum_freed)
//{
//#if GC_DEBUG_CONCISE_PRINTFS
// printf("(heap: %p size: %d)\n", h, (unsigned int)gc_heap_total_size(h));
//#endif
// // Mark global variables
// gc_mark(h, Cyc_global_variables); // Internal global used by the runtime
// // Marking it ensures all glos are marked
// {
// list l = global_table;
// for(; !nullp(l); l = cdr(l)){
// cvar_type *c = (cvar_type *)car(l);
// gc_mark(h, *(c->pvar)); // Mark actual object the global points to
// }
// }
// // TODO: what else to mark? gc_mark(
// // conservative mark?
// // weak refs?
// // finalize?
// return gc_sweep(h, sum_freed);
// // debug print free stats?
//}
// Mark globals as part of the tracing collector // Mark globals as part of the tracing collector
// This is called by the collector thread // This is called by the collector thread
void gc_mark_globals() void gc_mark_globals()
{ {
#if GC_DEBUG_CONCISE_PRINTFS #if GC_DEBUG_TRACE
printf("(gc_mark_globals heap: %p size: %d)\n", h, (unsigned int)gc_heap_total_size(h)); printf("(gc_mark_globals heap: %p size: %d)\n", h, (unsigned int)gc_heap_total_size(h));
printf("Cyc_global_variables %p\n", Cyc_global_variables);
#endif #endif
// Mark global variables // Mark global variables
printf("Cyc_global_variables %p\n", Cyc_global_variables);
gc_mark_black(Cyc_global_variables); // Internal global used by the runtime gc_mark_black(Cyc_global_variables); // Internal global used by the runtime
// Marking it ensures all glos are marked // Marking it ensures all glos are marked
{ {
@ -2450,7 +2425,9 @@ printf("Cyc_global_variables %p\n", Cyc_global_variables);
cvar_type *c = (cvar_type *)car(l); cvar_type *c = (cvar_type *)car(l);
object glo = *(c->pvar); object glo = *(c->pvar);
if (!nullp(glo)) { if (!nullp(glo)) {
printf("global pvar %p\n", glo); #if GC_DEBUG_TRACE
printf("global pvar %p\n", glo);
#endif
gc_mark_black(glo); // Mark actual object the global points to gc_mark_black(glo); // Mark actual object the global points to
} }
} }
@ -2717,34 +2694,12 @@ void GC(void *data, closure cont, object *args, int num_args)
scani++; scani++;
} }
//fprintf(stdout, "DEBUG done minor GC, alloci = %d\n", alloci);
// // Check if we need to do a major GC
// if (heap_grown) {
// size_t freed = 0, max_freed = 0;
//#if GC_DEBUG_CONCISE_PRINTFS
// time_t majorStart = time(NULL);
// fprintf(stdout, "DEBUG, starting major mark/sweep GC\n"); // JAE DEBUG
//#endif
// gc_mark(Cyc_heap, cont);
// for (i = 0; i < num_args; i++){
// gc_mark(Cyc_heap, args[i]);
// }
// max_freed = gc_collect(Cyc_heap, &freed);
//#if GC_DEBUG_CONCISE_PRINTFS
// printf("done, freed = %d, max_freed = %d, elapsed = %ld\n", freed, max_freed, time(NULL) - majorStart);
// //JAE_DEBUG++;
// //if (JAE_DEBUG == 2) exit(1); // JAE DEBUG
// for (i = 0; i < 20; i++){
// printf("gcMoveCountsDEBUG[%d] = %d\n", i, gcMoveCountsDEBUG[i]);
// }
//#endif
// }
// Cooperate with the collector thread // Cooperate with the collector thread
gc_mut_cooperate((gc_thread_data *)data); gc_mut_cooperate((gc_thread_data *)data);
printf("done with minor GC\n"); #ifdef GC_DEBUG_TRACE
printf("done with minor GC\n");
#endif
// Let it all go, Neo... // Let it all go, Neo...
longjmp(*(((gc_thread_data *)data)->jmp_start), 1); longjmp(*(((gc_thread_data *)data)->jmp_start), 1);
} }