[Git][ghc/ghc][wip/m32-fixes] 3 commits: rts: Post ticky entry counts to the eventlog
Ben Gamari
gitlab at gitlab.haskell.org
Mon Nov 23 19:13:25 UTC 2020
Ben Gamari pushed to branch wip/m32-fixes at Glasgow Haskell Compiler / GHC
Commits:
7e93ae8b by Ben Gamari at 2020-11-21T13:13:29-05:00
rts: Post ticky entry counts to the eventlog
We currently only post the entry counters, not the other global
counters as in my experience the former are more useful. We use the heap
profiler's census period to decide when to dump.
Also spruces up the documentation surrounding ticky-ticky a bit.
- - - - -
bc9c3916 by Ben Gamari at 2020-11-22T06:28:10-05:00
Implement -ddump-c-backend argument
To dump output of the C backend.
- - - - -
46d84a1c by Ben Gamari at 2020-11-23T14:13:18-05:00
rts/m32: Refactor handling of allocator seeding
Previously, in an attempt to reduce fragmentation, each new allocator
would map a region of M32_MAX_PAGES fresh pages to seed itself. However,
this ends up being extremely wasteful since it turns out that we often
use fewer than this. Consequently, these pages end up getting freed
which, ends up fragmenting our address space more than than we would
have if we had naively allocated pages on-demand.
Here we refactor m32 to avoid this waste while achieving the
fragmentation mitigation previously desired. In particular, we move all
page allocation into the global m32_alloc_page, which will pull a page
from the free page pool. If the free page pool is empty we then refill
it by allocating a region of M32_MAP_PAGES and adding them to the pool.
Furthermore, we do away with the initial seeding entirely. That is, the
allocator starts with no active pages: pages are rather allocated on an
as-needed basis.
On the whole this ends up being a pleasingly simple change,
simultaneously making m32 more efficient, more robust, and simpler.
Fixes #18980.
- - - - -
19 changed files:
- compiler/GHC/Driver/CodeOutput.hs
- compiler/GHC/Driver/Flags.hs
- compiler/GHC/Driver/Session.hs
- docs/users_guide/debugging.rst
- docs/users_guide/eventlog-formats.rst
- docs/users_guide/expected-undocumented-flags.txt
- docs/users_guide/profiling.rst
- includes/rts/EventLogFormat.h
- includes/rts/Flags.h
- rts/Proftimer.c
- rts/Proftimer.h
- rts/RtsFlags.c
- rts/RtsStartup.c
- rts/Ticky.c
- rts/Ticky.h
- rts/eventlog/EventLog.c
- rts/eventlog/EventLog.h
- rts/linker/M32Alloc.c
- rts/sm/GC.c
Changes:
=====================================
compiler/GHC/Driver/CodeOutput.hs
=====================================
@@ -138,7 +138,13 @@ outputC dflags filenm cmm_stream packages =
hPutStr h ("/* GHC_PACKAGES " ++ unwords pkg_names ++ "\n*/\n")
hPutStr h "#include \"Stg.h\"\n"
let platform = targetPlatform dflags
- writeC = printForC dflags h . cmmToC platform
+ writeC cmm = do
+ let doc = cmmToC platform cmm
+ dumpIfSet_dyn dflags Opt_D_dump_c_backend
+ "C backend output"
+ FormatC
+ doc
+ printForC dflags h doc
Stream.consume cmm_stream writeC
{-
=====================================
compiler/GHC/Driver/Flags.hs
=====================================
@@ -49,6 +49,7 @@ data DumpFlag
| Opt_D_dump_asm_conflicts
| Opt_D_dump_asm_stats
| Opt_D_dump_asm_expanded
+ | Opt_D_dump_c_backend
| Opt_D_dump_llvm
| Opt_D_dump_core_stats
| Opt_D_dump_deriv
=====================================
compiler/GHC/Driver/Session.hs
=====================================
@@ -2539,6 +2539,8 @@ dynamic_flags_deps = [
(setDumpFlag Opt_D_dump_asm_expanded)
, make_ord_flag defGhcFlag "ddump-llvm"
(NoArg $ setObjBackend LLVM >> setDumpFlag' Opt_D_dump_llvm)
+ , make_ord_flag defGhcFlag "ddump-c-backend"
+ (NoArg $ setDumpFlag' Opt_D_dump_c_backend)
, make_ord_flag defGhcFlag "ddump-deriv"
(setDumpFlag Opt_D_dump_deriv)
, make_ord_flag defGhcFlag "ddump-ds"
=====================================
docs/users_guide/debugging.rst
=====================================
@@ -552,6 +552,15 @@ LLVM code generator
LLVM code from the :ref:`LLVM code generator <llvm-code-gen>`
+C code generator
+~~~~~~~~~~~~~~~~
+
+.. ghc-flag:: -ddump-c-backend
+ :shortdesc: Dump C code produced by the C (unregisterised) backend.
+ :type: dynamic
+
+ :shortdesc: Dump C code produced by the C (unregisterised) backend.
+
Native code generator
~~~~~~~~~~~~~~~~~~~~~
=====================================
docs/users_guide/eventlog-formats.rst
=====================================
@@ -755,3 +755,34 @@ intended to provide insight into fragmentation of the non-moving heap.
:field Word32: number of live blocks.
Describes the occupancy of the *blk_sz* sub-heap.
+
+Ticky counters
+~~~~~~~~~~~~~~
+
+Programs compiled with :ghc-flag:`-ticky` and :ghc-flag:`-eventlog` and invoked
+with ``+RTS -lT`` will emit periodic samples of the ticky entry counters to the
+eventlog.
+
+.. event-type:: TICKY_COUNTER_DEF
+
+ :tag: 210
+ :length: variable
+ :field Word64: counter ID
+ :field Word16: arity/field count
+ :field String: argument kinds. This is the same as the synonymous field in the
+ textual ticky summary.
+ :field String: counter name
+
+ Defines a ticky counter.
+
+.. event-type:: TICKY_COUNTER_SAMPLE
+
+ :tag: 211
+ :length: fixed
+ :field Word64: counter ID
+ :field Word64: number of times closures of this type has been entered.
+ :field Word64: number of allocations (words)
+ :field Word64: number of times this has been allocated (words). Only
+ produced for modules compiled with :ghc-flag:`-ticky-allocd`.
+
+ Records the counter statistics at a moment in time.
=====================================
docs/users_guide/expected-undocumented-flags.txt
=====================================
@@ -118,5 +118,3 @@
-syslib
-this-component-id
-ticky-LNE
--ticky-allocd
--ticky-dyn-thunk
=====================================
docs/users_guide/profiling.rst
=====================================
@@ -1681,11 +1681,27 @@ Using “ticky-ticky” profiling (for implementors)
single: ticky-ticky profiling
.. ghc-flag:: -ticky
- :shortdesc: :ref:`Turn on ticky-ticky profiling <ticky-ticky>`
+ :shortdesc: Turn on :ref:`ticky-ticky profiling <ticky-ticky>`
:type: dynamic
:category:
- Enable ticky-ticky profiling.
+ Enable ticky-ticky profiling. By default this only tracks the allocations
+ *by* each closure type. See :ghc-flag:`-ticky-allocd` to keep track of
+ allocations *of* each closure type as well.
+
+.. ghc-flag:: -ticky-allocd
+ :shortdesc: Track the number of times each closure type is allocated.
+ :type: dynamic
+ :category:
+
+ Keep track of how much each closure type is allocated.
+
+.. ghc-flag:: -ticky-dyn-thunk
+ :shortdesc: Track allocations of dynamic thunks
+ :type: dynamic
+ :category:
+
+ Track allocations of dynamic thunks.
Because ticky-ticky profiling requires a certain familiarity with GHC
internals, we have moved the documentation to the GHC developers wiki.
=====================================
includes/rts/EventLogFormat.h
=====================================
@@ -154,12 +154,15 @@
#define EVENT_CONC_UPD_REM_SET_FLUSH 206
#define EVENT_NONMOVING_HEAP_CENSUS 207
+#define EVENT_TICKY_COUNTER_DEF 210
+#define EVENT_TICKY_COUNTER_SAMPLE 211
+
/*
* The highest event code +1 that ghc itself emits. Note that some event
* ranges higher than this are reserved but not currently emitted by ghc.
* This must match the size of the EventDesc[] array in EventLog.c
*/
-#define NUM_GHC_EVENT_TAGS 208
+#define NUM_GHC_EVENT_TAGS 212
#if 0 /* DEPRECATED EVENTS: */
/* we don't actually need to record the thread, it's implicit */
=====================================
includes/rts/Flags.h
=====================================
@@ -176,6 +176,7 @@ typedef struct _TRACE_FLAGS {
bool nonmoving_gc; /* trace nonmoving GC events */
bool sparks_sampled; /* trace spark events by a sampled method */
bool sparks_full; /* trace spark events 100% accurately */
+ bool ticky; /* trace ticky-ticky samples */
bool user; /* trace user events (emitted from Haskell code) */
char *trace_output; /* output filename for eventlog */
} TRACE_FLAGS;
=====================================
rts/Proftimer.c
=====================================
@@ -20,6 +20,12 @@ static bool do_prof_ticks = false; // enable profiling ticks
static bool do_heap_prof_ticks = false; // enable heap profiling ticks
+// Sampling of Ticky-Ticky profiler to eventlog
+#if defined(TICKY_TICKY) && defined(TRACING)
+static int ticks_to_ticky_sample = 0;
+bool performTickySample = false;
+#endif
+
// Number of ticks until next heap census
static int ticks_to_heap_profile;
@@ -83,6 +89,16 @@ handleProfTick(void)
}
#endif
+#if defined(TICKY_TICKY) && defined(TRACING)
+ if (RtsFlags.TraceFlags.ticky) {
+ ticks_to_ticky_sample--;
+ if (ticks_to_ticky_sample <= 0) {
+ ticks_to_ticky_sample = RtsFlags.ProfFlags.heapProfileIntervalTicks;
+ performTickySample = true;
+ }
+ }
+#endif
+
if (RELAXED_LOAD(&do_heap_prof_ticks)) {
ticks_to_heap_profile--;
if (ticks_to_heap_profile <= 0) {
=====================================
rts/Proftimer.h
=====================================
@@ -17,5 +17,6 @@ void stopHeapProfTimer ( void );
void startHeapProfTimer ( void );
extern bool performHeapProfile;
+extern bool performTickySample;
#include "EndPrivate.h"
=====================================
rts/RtsFlags.c
=====================================
@@ -235,6 +235,7 @@ void initRtsFlagsDefaults(void)
RtsFlags.TraceFlags.sparks_sampled= false;
RtsFlags.TraceFlags.sparks_full = false;
RtsFlags.TraceFlags.user = false;
+ RtsFlags.TraceFlags.ticky = false;
RtsFlags.TraceFlags.trace_output = NULL;
#endif
@@ -403,6 +404,9 @@ usage_text[] = {
" p par spark events (sampled)",
" f par spark events (full detail)",
" u user events (emitted from Haskell code)",
+#if defined(TICKY_TICKY)
+" T ticky-ticky counter samples",
+#endif
" a all event classes above",
# if defined(DEBUG)
" t add time stamps (only useful with -v)",
@@ -1855,6 +1859,11 @@ static void normaliseRtsOpts (void)
"the compacting collector.");
errorUsage();
}
+
+ if (RtsFlags.TraceFlags.ticky && RtsFlags.TickyFlags.showTickyStats) {
+ barf("The ticky-ticky eventlog output cannot be used in conjunction with\n"
+ "+RTS -r<file>.");
+ }
}
static void errorUsage (void)
@@ -2297,6 +2306,15 @@ static void read_trace_flags(const char *arg)
RtsFlags.TraceFlags.user = enabled;
enabled = true;
break;
+ case 'T':
+#if defined(TICKY_TICKY)
+ RtsFlags.TraceFlags.ticky = enabled;
+ enabled = true;
+ break;
+#else
+ errorBelch("Program not compiled with ticky-ticky support");
+ break;
+#endif
default:
errorBelch("unknown trace option: %c",*c);
break;
=====================================
rts/RtsStartup.c
=====================================
@@ -487,6 +487,17 @@ hs_exit_(bool wait_foreign)
*/
exitTimer(true);
+ /*
+ * Dump the ticky counter definitions
+ * We do this at the end of execution since tickers are registered in the
+ * course of program execution.
+ */
+#if defined(TICKY_TICKY) && defined(TRACING)
+ if (RtsFlags.TraceFlags.ticky) {
+ emitTickyCounterDefs();
+ }
+#endif
+
// set the terminal settings back to what they were
#if !defined(mingw32_HOST_OS)
resetTerminalSettings();
=====================================
rts/Ticky.c
=====================================
@@ -10,6 +10,8 @@
#include "PosixSource.h"
#include "Rts.h"
+#include "eventlog/EventLog.h"
+
/* Catch-all top-level counter struct. Allocations from CAFs will go
* here.
*/
@@ -46,6 +48,10 @@ static void printRegisteredCounterInfo (FILE *); /* fwd decl */
void
PrintTickyInfo(void)
{
+ if (RtsFlags.TraceFlags.ticky) {
+ barf("Ticky eventlog output can't be used with +RTS -r<file>");
+ }
+
unsigned long i;
unsigned long tot_thk_enters = ENT_STATIC_THK_MANY_ctr + ENT_DYN_THK_MANY_ctr
@@ -374,4 +380,19 @@ printRegisteredCounterInfo (FILE *tf)
}
}
+
+void emitTickyCounterDefs()
+{
+#if defined(TRACING)
+ postTickyCounterDefs(ticky_entry_ctrs);
+#endif
+}
+
+void emitTickyCounterSamples()
+{
+#if defined(TRACING)
+ postTickyCounterSamples(ticky_entry_ctrs);
+#endif
+}
+
#endif /* TICKY_TICKY */
=====================================
rts/Ticky.h
=====================================
@@ -8,4 +8,11 @@
#pragma once
-RTS_PRIVATE void PrintTickyInfo(void);
+#include "BeginPrivate.h"
+
+void PrintTickyInfo(void);
+
+void emitTickyCounterSamples(void);
+void emitTickyCounterDefs(void);
+
+#include "EndPrivate.h"
=====================================
rts/eventlog/EventLog.c
=====================================
@@ -119,7 +119,9 @@ char *EventDesc[] = {
[EVENT_CONC_SWEEP_BEGIN] = "Begin concurrent sweep",
[EVENT_CONC_SWEEP_END] = "End concurrent sweep",
[EVENT_CONC_UPD_REM_SET_FLUSH] = "Update remembered set flushed",
- [EVENT_NONMOVING_HEAP_CENSUS] = "Nonmoving heap census"
+ [EVENT_NONMOVING_HEAP_CENSUS] = "Nonmoving heap census",
+ [EVENT_TICKY_COUNTER_DEF] = "Ticky-ticky entry counter definition",
+ [EVENT_TICKY_COUNTER_SAMPLE] = "Ticky-ticky entry counter sample",
};
// Event type.
@@ -487,6 +489,14 @@ init_event_types(void)
eventTypes[t].size = 13;
break;
+ case EVENT_TICKY_COUNTER_DEF: // (counter_id, arity, arg_kinds, name)
+ eventTypes[t].size = EVENT_SIZE_DYNAMIC;
+ break;
+
+ case EVENT_TICKY_COUNTER_SAMPLE: // (counter_id, entry_count, allocs, allocd)
+ eventTypes[t].size = 8*4;
+ break;
+
default:
continue; /* ignore deprecated events */
}
@@ -1472,6 +1482,53 @@ void postProfBegin(void)
}
#endif /* PROFILING */
+#if defined(TICKY_TICKY)
+static void postTickyCounterDef(EventsBuf *eb, StgEntCounter *p)
+{
+ StgWord len = 8 + 2 + strlen(p->arg_kinds)+1 + strlen(p->str)+1;
+ ensureRoomForVariableEvent(eb, len);
+ postEventHeader(eb, EVENT_TICKY_COUNTER_DEF);
+ postPayloadSize(eb, len);
+ postWord64(eb, (uint64_t) p);
+ postWord16(eb, (uint16_t) p->arity);
+ postString(eb, p->arg_kinds);
+ postString(eb, p->str);
+}
+
+void postTickyCounterDefs(StgEntCounter *counters)
+{
+ ACQUIRE_LOCK(&eventBufMutex);
+ for (StgEntCounter *p = counters; p != NULL; p = p->link) {
+ postTickyCounterDef(&eventBuf, p);
+ }
+ RELEASE_LOCK(&eventBufMutex);
+}
+
+static void postTickyCounterSample(EventsBuf *eb, StgEntCounter *p)
+{
+ if ( p->entry_count == 0
+ && p->allocs == 0
+ && p->allocd == 0)
+ return;
+
+ ensureRoomForEvent(eb, EVENT_TICKY_COUNTER_SAMPLE);
+ postEventHeader(eb, EVENT_TICKY_COUNTER_SAMPLE);
+ postWord64(eb, (uint64_t) p);
+ postWord64(eb, p->entry_count);
+ postWord64(eb, p->allocs);
+ postWord64(eb, p->allocd);
+}
+
+void postTickyCounterSamples(StgEntCounter *counters)
+{
+ ACQUIRE_LOCK(&eventBufMutex);
+ for (StgEntCounter *p = counters; p != NULL; p = p->link) {
+ postTickyCounterSample(&eventBuf, p);
+ }
+ RELEASE_LOCK(&eventBufMutex);
+}
+#endif /* TICKY_TICKY */
+
void printAndClearEventBuf (EventsBuf *ebuf)
{
closeBlockMarker(ebuf);
=====================================
rts/eventlog/EventLog.h
=====================================
@@ -173,6 +173,11 @@ void postConcMarkEnd(StgWord32 marked_obj_count);
void postNonmovingHeapCensus(int log_blk_size,
const struct NonmovingAllocCensus *census);
+#if defined(TICKY_TICKY)
+void postTickyCounterDefs(StgEntCounter *p);
+void postTickyCounterSamples(StgEntCounter *p);
+#endif /* TICKY_TICKY */
+
#else /* !TRACING */
INLINE_HEADER void postSchedEvent (Capability *cap STG_UNUSED,
=====================================
rts/linker/M32Alloc.c
=====================================
@@ -81,6 +81,7 @@ The allocator manages two kinds of allocations:
* small allocations, which are allocated into a set of "nursery" pages
(recorded in m32_allocator_t.pages; the size of the set is <= M32_MAX_PAGES)
+
* large allocations are those larger than a page and are mapped directly
Each page (or the first page of a large allocation) begins with a m32_page_t
@@ -126,7 +127,9 @@ code accordingly).
To avoid unnecessary mapping/unmapping we maintain a global list of free pages
(which can grow up to M32_MAX_FREE_PAGE_POOL_SIZE long). Pages on this list
have the usual m32_page_t header and are linked together with
-m32_page_t.free_page.next.
+m32_page_t.free_page.next. When run out of free pages we allocate a chunk of
+M32_MAP_PAGES to both avoid fragmenting our address space and amortize the
+runtime cost of the mapping.
The allocator is *not* thread-safe.
@@ -139,7 +142,12 @@ The allocator is *not* thread-safe.
* M32 ALLOCATOR (see Note [M32 Allocator]
***************************************************************************/
+/* How many open pages each allocator will keep around? */
#define M32_MAX_PAGES 32
+/* How many pages should we map at once when re-filling the free page pool? */
+#define M32_MAP_PAGES 32
+/* Upper bound on the number of pages to keep in the free page pool */
+#define M32_MAX_FREE_PAGE_POOL_SIZE 64
/**
* Page header
@@ -204,7 +212,6 @@ struct m32_allocator_t {
*
* We keep a small pool of free pages around to avoid fragmentation.
*/
-#define M32_MAX_FREE_PAGE_POOL_SIZE 16
struct m32_page_t *m32_free_page_pool = NULL;
unsigned int m32_free_page_pool_size = 0;
// TODO
@@ -250,18 +257,29 @@ m32_release_page(struct m32_page_t *page)
static struct m32_page_t *
m32_alloc_page(void)
{
- if (m32_free_page_pool_size > 0) {
- struct m32_page_t *page = m32_free_page_pool;
- m32_free_page_pool = page->free_page.next;
- m32_free_page_pool_size --;
- return page;
- } else {
- struct m32_page_t *page = mmapForLinker(getPageSize(), PROT_READ | PROT_WRITE, MAP_ANONYMOUS, -1, 0);
+ if (m32_free_page_pool_size == 0) {
+ /*
+ * Free page pool is empty; refill it with a new batch of M32_MAP_PAGES
+ * pages.
+ */
+ struct m32_page_t *chunk = mmapForLinker(getPageSize() * M32_MAP_PAGES, PROT_READ | PROT_WRITE, MAP_ANONYMOUS, -1, 0);
if (page > (struct m32_page_t *) 0xffffffff) {
barf("m32_alloc_page: failed to get allocation in lower 32-bits");
}
- return page;
+
+ for (int i=0; i < M32_MAP_PAGES; i++) {
+ struct m32_page_t *page = chunk[i];
+ page->free_page.next = &page[i+1];
+ }
+ chunk[M32_MAP_PAGES-1]->free_page.next = m32_free_page_pool;
+ m32_free_page_pool = &chunk[0];
+ m32_free_page_pool_size += M32_MAP_PAGES;
}
+
+ struct m32_page_t *page = m32_free_page_pool;
+ m32_free_page_pool = page->free_page.next;
+ m32_free_page_pool_size --;
+ return page;
}
/**
@@ -276,19 +294,6 @@ m32_allocator_new(bool executable)
stgMallocBytes(sizeof(m32_allocator), "m32_new_allocator");
memset(alloc, 0, sizeof(struct m32_allocator_t));
alloc->executable = executable;
-
- // Preallocate the initial M32_MAX_PAGES to ensure that they don't
- // fragment the memory.
- size_t pgsz = getPageSize();
- char* bigchunk = mmapForLinker(pgsz * M32_MAX_PAGES, PROT_READ | PROT_WRITE, MAP_ANONYMOUS,-1,0);
- if (bigchunk == NULL)
- barf("m32_allocator_init: Failed to map");
-
- int i;
- for (i=0; i<M32_MAX_PAGES; i++) {
- alloc->pages[i] = (struct m32_page_t *) (bigchunk + i*pgsz);
- alloc->pages[i]->current_size = sizeof(struct m32_page_t);
- }
return alloc;
}
@@ -350,7 +355,9 @@ m32_allocator_push_filled_list(struct m32_page_t **head, struct m32_page_t *page
void
m32_allocator_flush(m32_allocator *alloc) {
for (int i=0; i<M32_MAX_PAGES; i++) {
- if (alloc->pages[i]->current_size == sizeof(struct m32_page_t)) {
+ if (alloc->pages[i] == NULL) {
+ continue;
+ } else if (alloc->pages[i]->current_size == sizeof(struct m32_page_t)) {
// the page is empty, free it
m32_release_page(alloc->pages[i]);
} else {
=====================================
rts/sm/GC.c
=====================================
@@ -38,6 +38,7 @@
#include "Sanity.h"
#include "BlockAlloc.h"
#include "ProfHeap.h"
+#include "Proftimer.h"
#include "Weak.h"
#include "Prelude.h"
#include "RtsSignals.h"
@@ -52,6 +53,7 @@
#include "CNF.h"
#include "RtsFlags.h"
#include "NonMoving.h"
+#include "Ticky.h"
#include <string.h> // for memset()
#include <unistd.h>
@@ -903,6 +905,16 @@ GarbageCollect (uint32_t collect_gen,
ACQUIRE_SM_LOCK;
}
+#if defined(TICKY_TICKY)
+ // Post ticky counter sample.
+ // We do this at the end of execution since tickers are registered in the
+ // course of program execution.
+ if (performTickySample) {
+ emitTickyCounterSamples();
+ performTickySample = false;
+ }
+#endif
+
// send exceptions to any threads which were about to die
RELEASE_SM_LOCK;
resurrectThreads(resurrected_threads);
View it on GitLab: https://gitlab.haskell.org/ghc/ghc/-/compare/5e90343aae50d1ccf9949299b7f4de6ac471d379...46d84a1cc0f080430d36df5d5b3475a8de36fef1
--
View it on GitLab: https://gitlab.haskell.org/ghc/ghc/-/compare/5e90343aae50d1ccf9949299b7f4de6ac471d379...46d84a1cc0f080430d36df5d5b3475a8de36fef1
You're receiving this email because of your account on gitlab.haskell.org.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.haskell.org/pipermail/ghc-commits/attachments/20201123/8723dae5/attachment-0001.html>
More information about the ghc-commits
mailing list