sgen_object_layout_dump (stdout);
}
- sgen_restart_world (0, NULL);
+ sgen_restart_world (0);
binary_protocol_domain_unload_end (domain);
binary_protocol_flush_buffers (FALSE);
}
}
-void
-sgen_client_log_timing (GGTimingInfo *info, mword promoted_size, mword major_used_size)
-{
- SgenMajorCollector *major_collector = sgen_get_major_collector ();
- mword num_major_sections = major_collector->get_num_major_sections ();
- char full_timing_buff [1024];
- full_timing_buff [0] = '\0';
-
- if (!info->is_overflow)
- sprintf (full_timing_buff, "total %.2fms", info->stw_time / 10000.0f);
- if (info->generation == GENERATION_OLD)
- mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MAJOR%s: (%s) pause %.2fms, %s los size: %dK in use: %dK",
- info->is_overflow ? "_OVERFLOW" : "",
- info->reason ? info->reason : "",
- (int)info->total_time / 10000.0f,
- full_timing_buff,
- los_memory_usage_total / 1024,
- los_memory_usage / 1024);
- else
- mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MINOR%s: (%s) pause %.2fms, %s promoted %dK major size: %dK in use: %dK los size: %dK in use: %dK",
- info->is_overflow ? "_OVERFLOW" : "",
- info->reason ? info->reason : "",
- (int)info->total_time / 10000.0f,
- full_timing_buff,
- (int)promoted_size / 1024,
- major_collector->section_size * num_major_sections / 1024,
- major_used_size / 1024,
- los_memory_usage_total / 1024,
- los_memory_usage / 1024);
-}
-
/*
* Debugging
*/
/* LOCKING: assumes the GC lock is held */
void
-sgen_client_restart_world (int generation, GGTimingInfo *timing)
+sgen_client_restart_world (int generation, gint64 *stw_time)
{
TV_DECLARE (end_sw);
TV_DECLARE (start_handshake);
*/
release_gc_locks ();
- if (timing) {
- timing [0].stw_time = usec;
- }
+ *stw_time = usec;
}
void
* single-threaded programs this is a nop.
*/
void sgen_client_stop_world (int generation);
-void sgen_client_restart_world (int generation, GGTimingInfo *timing);
+void sgen_client_restart_world (int generation, gint64 *stw_time);
/*
* Must return FALSE. The bridge is not supported outside of Mono.
void sgen_client_mark_togglerefs (char *start, char *end, ScanCopyContext ctx);
void sgen_client_clear_togglerefs (char *start, char *end, ScanCopyContext ctx);
-/*
- * Called after collections, reporting the amount of time they took. No action is
- * necessary.
- */
-void sgen_client_log_timing (GGTimingInfo *info, mword promoted_size, mword major_used_size);
-
/*
* Called to handle `MONO_GC_PARAMS` and `MONO_GC_DEBUG` options. The `handle` functions
* must return TRUE if they have recognized and processed the option, FALSE otherwise.
* Return whether any objects were late-pinned due to being out of memory.
*/
static gboolean
-collect_nursery (SgenGrayQueue *unpin_queue, gboolean finish_up_concurrent_mark)
+collect_nursery (const char *reason, gboolean is_overflow, SgenGrayQueue *unpin_queue, gboolean finish_up_concurrent_mark)
{
gboolean needs_major;
size_t max_garbage_amount;
binary_protocol_flush_buffers (FALSE);
- sgen_memgov_minor_collection_end ();
+ sgen_memgov_minor_collection_end (reason, is_overflow);
/*objects are late pinned because of lack of memory, so a major is a good call*/
needs_major = objects_pinned > 0;
}
static void
-major_start_collection (gboolean concurrent, size_t *old_next_pin_slot)
+major_start_collection (const char *reason, gboolean concurrent, size_t *old_next_pin_slot)
{
SgenObjectOperations *object_ops;
reset_pinned_from_failed_allocation ();
- sgen_memgov_major_collection_start ();
+ sgen_memgov_major_collection_start (concurrent, reason);
//count_ref_nonref_objs ();
//consistency_check ();
}
static void
-major_finish_collection (const char *reason, size_t old_next_pin_slot, gboolean forced)
+major_finish_collection (const char *reason, gboolean is_overflow, size_t old_next_pin_slot, gboolean forced)
{
ScannedObjectCounts counts;
SgenObjectOperations *object_ops;
g_assert (sgen_gray_object_queue_is_empty (&gray_queue));
- sgen_memgov_major_collection_end (forced);
+ sgen_memgov_major_collection_end (forced, concurrent_collection_in_progress, reason, is_overflow);
current_collection_generation = -1;
memset (&counts, 0, sizeof (ScannedObjectCounts));
}
static gboolean
-major_do_collection (const char *reason, gboolean forced)
+major_do_collection (const char *reason, gboolean is_overflow, gboolean forced)
{
TV_DECLARE (time_start);
TV_DECLARE (time_end);
/* world must be stopped already */
TV_GETTIME (time_start);
- major_start_collection (FALSE, &old_next_pin_slot);
- major_finish_collection (reason, old_next_pin_slot, forced);
+ major_start_collection (reason, FALSE, &old_next_pin_slot);
+ major_finish_collection (reason, is_overflow, old_next_pin_slot, forced);
TV_GETTIME (time_end);
gc_stats.major_gc_time += TV_ELAPSED (time_start, time_end);
binary_protocol_concurrent_start ();
// FIXME: store reason and pass it when finishing
- major_start_collection (TRUE, NULL);
+ major_start_collection (reason, TRUE, NULL);
gray_queue_redirect (&gray_queue);
current_collection_generation = GENERATION_OLD;
sgen_cement_reset ();
- major_finish_collection ("finishing", -1, forced);
+ major_finish_collection ("finishing", FALSE, -1, forced);
if (whole_heap_check_before_collection)
sgen_check_whole_heap (FALSE);
void
sgen_perform_collection (size_t requested_size, int generation_to_collect, const char *reason, gboolean wait_to_finish)
{
- TV_DECLARE (gc_start);
- TV_DECLARE (gc_end);
TV_DECLARE (gc_total_start);
TV_DECLARE (gc_total_end);
- GGTimingInfo infos [2];
int overflow_generation_to_collect = -1;
int oldest_generation_collected = generation_to_collect;
const char *overflow_reason = NULL;
SGEN_ASSERT (0, generation_to_collect == GENERATION_NURSERY || generation_to_collect == GENERATION_OLD, "What generation is this?");
- TV_GETTIME (gc_start);
-
sgen_stop_world (generation_to_collect);
TV_GETTIME (gc_total_start);
if (concurrent_collection_in_progress)
major_update_concurrent_collection ();
- if (collect_nursery (NULL, FALSE) && !concurrent_collection_in_progress) {
+ if (collect_nursery (reason, FALSE, NULL, FALSE) && !concurrent_collection_in_progress) {
overflow_generation_to_collect = GENERATION_OLD;
overflow_reason = "Minor overflow";
}
} else {
SGEN_ASSERT (0, generation_to_collect == GENERATION_OLD, "We should have handled nursery collections above");
if (major_collector.is_concurrent && !wait_to_finish) {
- collect_nursery (NULL, FALSE);
+ collect_nursery ("Concurrent start", FALSE, NULL, FALSE);
major_start_concurrent_collection (reason);
oldest_generation_collected = GENERATION_NURSERY;
- } else if (major_do_collection (reason, wait_to_finish)) {
+ } else if (major_do_collection (reason, FALSE, wait_to_finish)) {
overflow_generation_to_collect = GENERATION_NURSERY;
overflow_reason = "Excessive pinning";
}
}
- TV_GETTIME (gc_end);
-
- memset (infos, 0, sizeof (infos));
- infos [0].generation = oldest_generation_collected;
- infos [0].reason = reason;
- infos [0].is_overflow = FALSE;
- infos [1].generation = -1;
- infos [0].total_time = SGEN_TV_ELAPSED (gc_start, gc_end);
-
if (overflow_generation_to_collect != -1) {
SGEN_ASSERT (0, !concurrent_collection_in_progress, "We don't yet support overflow collections with the concurrent collector");
* or the nursery is fully pinned.
*/
- infos [1].generation = overflow_generation_to_collect;
- infos [1].reason = overflow_reason;
- infos [1].is_overflow = TRUE;
- gc_start = gc_end;
-
if (overflow_generation_to_collect == GENERATION_NURSERY)
- collect_nursery (NULL, FALSE);
+ collect_nursery (overflow_reason, TRUE, NULL, FALSE);
else
- major_do_collection (overflow_reason, wait_to_finish);
-
- TV_GETTIME (gc_end);
- infos [1].total_time = SGEN_TV_ELAPSED (gc_start, gc_end);
+ major_do_collection (overflow_reason, TRUE, wait_to_finish);
oldest_generation_collected = MAX (oldest_generation_collected, overflow_generation_to_collect);
}
TV_GETTIME (gc_total_end);
time_max = MAX (time_max, TV_ELAPSED (gc_total_start, gc_total_end));
- sgen_restart_world (oldest_generation_collected, infos);
+ sgen_restart_world (oldest_generation_collected);
}
/*
/* LOCKING: assumes the GC lock is held */
void
-sgen_restart_world (int generation, GGTimingInfo *timing)
+sgen_restart_world (int generation)
{
long long major_total = -1, major_marked = -1, los_total = -1, los_marked = -1;
+ gint64 stw_time;
SGEN_ASSERT (0, world_is_stopped, "Why are we restarting a running world?");
world_is_stopped = FALSE;
- sgen_client_restart_world (generation, timing);
+ sgen_client_restart_world (generation, &stw_time);
binary_protocol_world_restarted (generation, sgen_timestamp ());
if (sgen_client_bridge_need_processing ())
sgen_client_bridge_processing_finish (generation);
- sgen_memgov_collection_end (generation, timing, timing ? 2 : 0);
+ sgen_memgov_collection_end (generation, stw_time);
}
gboolean
sgen_stop_world (0);
sgen_clear_nursery_fragments ();
sgen_check_whole_heap (FALSE);
- sgen_restart_world (0, NULL);
+ sgen_restart_world (0);
}
gint64
INTERNAL_MEM_CARDTABLE_MOD_UNION,
INTERNAL_MEM_BINARY_PROTOCOL,
INTERNAL_MEM_TEMPORARY,
+ INTERNAL_MEM_LOG_ENTRY,
INTERNAL_MEM_FIRST_CLIENT
};
/* STW */
-typedef struct {
- int generation;
- const char *reason;
- gboolean is_overflow;
- gint64 total_time;
- gint64 stw_time;
-} GGTimingInfo;
-
void sgen_stop_world (int generation);
-void sgen_restart_world (int generation, GGTimingInfo *timing);
+void sgen_restart_world (int generation);
gboolean sgen_is_world_stopped (void);
gboolean sgen_set_allow_synchronous_major (gboolean flag);
#define MIN_MINOR_COLLECTION_ALLOWANCE ((mword)(DEFAULT_NURSERY_SIZE * default_allowance_nursery_size_ratio))
+static SgenPointerQueue log_entries = SGEN_POINTER_QUEUE_INIT (INTERNAL_MEM_TEMPORARY);
+static MonoCoopMutex log_entries_mutex;
+
mword total_promoted_size = 0;
mword total_allocated_major = 0;
static mword total_promoted_size_start;
static mword total_alloc = 0;
static mword total_alloc_max = 0;
+static SGEN_TV_DECLARE(last_minor_start);
+static SGEN_TV_DECLARE(last_major_start);
+
/* GC triggers. */
static gboolean debug_print_allowance = FALSE;
sgen_memgov_minor_collection_start (void)
{
total_promoted_size_start = total_promoted_size;
+ SGEN_TV_GETTIME (last_minor_start);
+}
+
+static void
+sgen_add_log_entry (SgenLogEntry *log_entry)
+{
+ mono_coop_mutex_lock (&log_entries_mutex);
+ sgen_pointer_queue_add (&log_entries, log_entry);
+ mono_coop_mutex_unlock (&log_entries_mutex);
}
void
-sgen_memgov_minor_collection_end (void)
+sgen_memgov_minor_collection_end (const char *reason, gboolean is_overflow)
{
+ if (mono_trace_is_traced (G_LOG_LEVEL_INFO, MONO_TRACE_GC)) {
+ SgenLogEntry *log_entry = (SgenLogEntry*)sgen_alloc_internal (INTERNAL_MEM_LOG_ENTRY);
+ SGEN_TV_DECLARE (current_time);
+ SGEN_TV_GETTIME (current_time);
+
+ log_entry->type = SGEN_LOG_NURSERY;
+ log_entry->reason = reason;
+ log_entry->is_overflow = is_overflow;
+ log_entry->time = SGEN_TV_ELAPSED (last_minor_start, current_time);
+ log_entry->promoted_size = total_promoted_size - total_promoted_size_start;
+ log_entry->major_size = major_collector.get_num_major_sections () * major_collector.section_size;
+ log_entry->major_size_in_use = last_used_slots_size + total_allocated_major - total_allocated_major_end;
+ log_entry->los_size = los_memory_usage_total;
+ log_entry->los_size_in_use = los_memory_usage;
+
+ sgen_add_log_entry (log_entry);
+ }
}
void
void
sgen_memgov_major_post_sweep (mword used_slots_size)
{
- mword num_major_sections = major_collector.get_num_major_sections ();
+ if (mono_trace_is_traced (G_LOG_LEVEL_INFO, MONO_TRACE_GC)) {
+ SgenLogEntry *log_entry = (SgenLogEntry*)sgen_alloc_internal (INTERNAL_MEM_LOG_ENTRY);
+
+ log_entry->type = SGEN_LOG_MAJOR_SWEEP_FINISH;
+ log_entry->major_size = major_collector.get_num_major_sections () * major_collector.section_size;
+ log_entry->major_size_in_use = used_slots_size + total_allocated_major - total_allocated_major_end;
- mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MAJOR_SWEEP: major size: %dK in use: %dK",
- num_major_sections * major_collector.section_size / 1024,
- (used_slots_size + total_allocated_major - total_allocated_major_end) / 1024);
+ sgen_add_log_entry (log_entry);
+ }
last_used_slots_size = used_slots_size;
}
void
-sgen_memgov_major_collection_start (void)
+sgen_memgov_major_collection_start (gboolean concurrent, const char *reason)
{
need_calculate_minor_collection_allowance = TRUE;
major_start_heap_size = get_heap_size ();
if (debug_print_allowance) {
SGEN_LOG (0, "Starting collection with heap size %ld bytes", (long)major_start_heap_size);
}
+ if (concurrent && mono_trace_is_traced (G_LOG_LEVEL_INFO, MONO_TRACE_GC)) {
+ SgenLogEntry *log_entry = (SgenLogEntry*)sgen_alloc_internal (INTERNAL_MEM_LOG_ENTRY);
+
+ log_entry->type = SGEN_LOG_MAJOR_CONC_START;
+ log_entry->reason = reason;
+
+ sgen_add_log_entry (log_entry);
+ }
+ SGEN_TV_GETTIME (last_major_start);
}
void
-sgen_memgov_major_collection_end (gboolean forced)
+sgen_memgov_major_collection_end (gboolean forced, gboolean concurrent, const char *reason, gboolean is_overflow)
{
- last_collection_los_memory_usage = los_memory_usage;
+ if (mono_trace_is_traced (G_LOG_LEVEL_INFO, MONO_TRACE_GC)) {
+ SgenLogEntry *log_entry = (SgenLogEntry*)sgen_alloc_internal (INTERNAL_MEM_LOG_ENTRY);
+ SGEN_TV_DECLARE (current_time);
+ SGEN_TV_GETTIME (current_time);
+
+ if (concurrent) {
+ log_entry->type = SGEN_LOG_MAJOR_CONC_FINISH;
+ } else {
+ log_entry->type = SGEN_LOG_MAJOR_SERIAL;
+ }
+ log_entry->time = SGEN_TV_ELAPSED (last_major_start, current_time);
+ log_entry->reason = reason;
+ log_entry->is_overflow = is_overflow;
+ log_entry->los_size = los_memory_usage_total;
+ log_entry->los_size_in_use = los_memory_usage;
+
+ sgen_add_log_entry (log_entry);
+ }
+ last_collection_los_memory_usage = los_memory_usage;
total_allocated_major_end = total_allocated_major;
if (forced) {
sgen_get_major_collector ()->finish_sweeping ();
{
}
+static void
+sgen_output_log_entry (SgenLogEntry *entry, gint64 stw_time, int generation)
+{
+ char full_timing_buff [1024];
+ full_timing_buff [0] = '\0';
+
+ if (!entry->is_overflow)
+ sprintf (full_timing_buff, "stw %.2fms", stw_time / 10000.0f);
+
+ switch (entry->type) {
+ case SGEN_LOG_NURSERY:
+ mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MINOR%s: (%s) time %.2fms, %s promoted %dK major size: %dK in use: %dK los size: %dK in use: %dK",
+ entry->is_overflow ? "_OVERFLOW" : "",
+ entry->reason ? entry->reason : "",
+ entry->time / 10000.0f,
+ (generation == GENERATION_NURSERY) ? full_timing_buff : "",
+ entry->promoted_size / 1024,
+ entry->major_size / 1024,
+ entry->major_size_in_use / 1024,
+ entry->los_size / 1024,
+ entry->los_size_in_use / 1024);
+ break;
+ case SGEN_LOG_MAJOR_SERIAL:
+ mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MAJOR%s: (%s) time %.2fms, %s los size: %dK in use: %dK",
+ entry->is_overflow ? "_OVERFLOW" : "",
+ entry->reason ? entry->reason : "",
+ (int)entry->time / 10000.0f,
+ full_timing_buff,
+ entry->los_size / 1024,
+ entry->los_size_in_use / 1024);
+ break;
+ case SGEN_LOG_MAJOR_CONC_START:
+ mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MAJOR_CONCURRENT_START: (%s)", entry->reason ? entry->reason : "");
+ break;
+ case SGEN_LOG_MAJOR_CONC_FINISH:
+ mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MAJOR_CONCURRENT_FINISH: (%s) time %.2fms, %s los size: %dK in use: %dK",
+ entry->reason ? entry->reason : "",
+ entry->time / 10000.0f,
+ full_timing_buff,
+ entry->los_size / 1024,
+ entry->los_size_in_use / 1024);
+ break;
+ case SGEN_LOG_MAJOR_SWEEP_FINISH:
+ mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_GC, "GC_MAJOR_SWEEP: major size: %dK in use: %dK",
+ entry->major_size / 1024,
+ entry->major_size_in_use / 1024);
+ break;
+ default:
+ SGEN_ASSERT (0, FALSE, "Invalid log entry type");
+ break;
+ }
+}
+
void
-sgen_memgov_collection_end (int generation, GGTimingInfo* info, int info_count)
+sgen_memgov_collection_end (int generation, gint64 stw_time)
{
- int i;
- for (i = 0; i < info_count; ++i) {
- if (info[i].generation != -1)
- sgen_client_log_timing (&info [i], total_promoted_size - total_promoted_size_start, last_used_slots_size + total_allocated_major - total_allocated_major_end);
+ /*
+ * At this moment the world has been restarted which means we can log all pending entries
+ * without risking deadlocks.
+ */
+ if (mono_trace_is_traced (G_LOG_LEVEL_INFO, MONO_TRACE_GC)) {
+ size_t i;
+ SGEN_ASSERT (0, !sgen_is_world_stopped (), "We can't log if the world is stopped");
+ mono_coop_mutex_lock (&log_entries_mutex);
+ for (i = 0; i < log_entries.next_slot; i++) {
+ sgen_output_log_entry (log_entries.data [i], stw_time, generation);
+ sgen_free_internal (log_entries.data [i], INTERNAL_MEM_LOG_ENTRY);
+ }
+ sgen_pointer_queue_clear (&log_entries);
+ mono_coop_mutex_unlock (&log_entries_mutex);
}
}
mono_counters_register ("Memgov alloc", MONO_COUNTER_GC | MONO_COUNTER_WORD | MONO_COUNTER_BYTES | MONO_COUNTER_VARIABLE, &total_alloc);
mono_counters_register ("Memgov max alloc", MONO_COUNTER_GC | MONO_COUNTER_WORD | MONO_COUNTER_BYTES | MONO_COUNTER_MONOTONIC, &total_alloc_max);
+ mono_coop_mutex_init (&log_entries_mutex);
+
+ sgen_register_fixed_internal_mem_type (INTERNAL_MEM_LOG_ENTRY, sizeof (SgenLogEntry));
+
if (max_heap == 0)
return;
/* GC trigger heuristics */
void sgen_memgov_minor_collection_start (void);
-void sgen_memgov_minor_collection_end (void);
+void sgen_memgov_minor_collection_end (const char *reason, gboolean is_overflow);
void sgen_memgov_major_pre_sweep (void);
void sgen_memgov_major_post_sweep (mword used_slots_size);
-void sgen_memgov_major_collection_start (void);
-void sgen_memgov_major_collection_end (gboolean forced);
+void sgen_memgov_major_collection_start (gboolean concurrent, const char *reason);
+void sgen_memgov_major_collection_end (gboolean forced, gboolean concurrent, const char *reason, gboolean is_overflow);
void sgen_memgov_collection_start (int generation);
-void sgen_memgov_collection_end (int generation, GGTimingInfo* info, int info_count);
+void sgen_memgov_collection_end (int generation, gint64 stw);
gboolean sgen_need_major_collection (mword space_needed);
SGEN_ALLOC_ACTIVATE = 2
} SgenAllocFlags;
+typedef enum {
+ SGEN_LOG_NURSERY,
+ SGEN_LOG_MAJOR_SERIAL,
+ SGEN_LOG_MAJOR_CONC_START,
+ SGEN_LOG_MAJOR_CONC_FINISH,
+ SGEN_LOG_MAJOR_SWEEP_FINISH
+} SgenLogType;
+
+typedef struct {
+ SgenLogType type;
+ const char *reason;
+ gboolean is_overflow;
+ gint64 time;
+ mword promoted_size;
+ mword major_size;
+ mword major_size_in_use;
+ mword los_size;
+ mword los_size_in_use;
+} SgenLogEntry;
+
/* OS memory allocation */
void* sgen_alloc_os_memory (size_t size, SgenAllocFlags flags, const char *assert_description);
void* sgen_alloc_os_memory_aligned (size_t size, mword alignment, SgenAllocFlags flags, const char *assert_description);