Commit 8b18faef authored by Simon Marlow's avatar Simon Marlow

Add fast event logging

Generate binary log files from the RTS containing a log of runtime
events with timestamps.  The log file can be visualised in various
ways, for investigating runtime behaviour and debugging performance
problems.  See for example the forthcoming ThreadScope viewer.

New GHC option:

  -eventlog   (link-time option) Enables event logging.

  +RTS -l     (runtime option) Generates <prog>.eventlog with
              the binary event information.

This replaces some of the tracing machinery we already had in the RTS:
e.g. +RTS -vg  for GC tracing (we should do this using the new event
logging instead).

Event logging has almost no runtime cost when it isn't enabled, though
in the future we might add more fine-grained events and this might
change; hence having a link-time option and compiling a separate
version of the RTS for event logging.  There's a small runtime cost
for enabling event-logging, for most programs it shouldn't make much
difference.

(Todo: docs)
parent f8f4cb3f
......@@ -106,6 +106,7 @@ static_flags = [
------- ways --------------------------------------------------------
, Flag "prof" (NoArg (addWay WayProf)) Supported
, Flag "eventlog" (NoArg (addWay WayEventLog)) Supported
, Flag "ticky" (NoArg (addWay WayTicky)) Supported
, Flag "parallel" (NoArg (addWay WayPar)) Supported
, Flag "gransim" (NoArg (addWay WayGran)) Supported
......
......@@ -320,6 +320,7 @@ data WayName
= WayThreaded
| WayDebug
| WayProf
| WayEventLog
| WayTicky
| WayPar
| WayGran
......@@ -359,6 +360,7 @@ allowed_combination way = and [ x `allowedWith` y
WayProf `allowedWith` WayNDP = True
WayThreaded `allowedWith` WayProf = True
WayThreaded `allowedWith` WayEventLog = True
_ `allowedWith` _ = False
......@@ -425,6 +427,10 @@ way_details =
, "-DPROFILING"
, "-optc-DPROFILING" ]),
(WayEventLog, Way "l" True "RTS Event Logging"
[ "-DEVENTLOG"
, "-optc-DEVENTLOG" ]),
(WayTicky, Way "t" True "Ticky-ticky Profiling"
[ "-DTICKY_TICKY"
, "-optc-DTICKY_TICKY" ]),
......
/* -----------------------------------------------------------------------------
*
* (c) The GHC Team, 2008-2009
*
* Event log format
*
* The log format is designed to be extensible: old tools should be
* able to parse (but not necessarily understand all of) new versions
* of the format, and new tools will be able to understand old log
* files.
*
* Each event has a specific format. If you add new events, give them
* new numbers: we never re-use old event numbers.
*
* - The format is endian-independent: all values are represented in
* bigendian order.
*
* - The format is extensible:
*
* - The header describes each event type and its length. Tools
* that don't recognise a particular event type can skip those events.
*
* - There is room for extra information in the event type
* specification, which can be ignored by older tools.
*
* - Events can have extra information added, but existing fields
* cannot be changed. Tools should ignore extra fields at the
* end of the event record.
*
* - Old event type ids are never re-used; just take a new identifier.
*
*
* The format
* ----------
*
* log : EVENT_HEADER_BEGIN
* EventType*
* EVENT_HEADER_END
* EVENT_DATA_BEGIN
* Event*
* EVENT_DATA_END
*
* EventType :
* EVENT_ET_BEGIN
* Word16 -- unique identifier for this event
* Int16 -- >=0 size of the event in bytes (minus the header)
* -- -1 variable size
* Word32 -- length of the next field in bytes
* Word8* -- string describing the event
* Word32 -- length of the next field in bytes
* Word8* -- extra info (for future extensions)
* EVENT_ET_END
*
* Event :
* Word16 -- event_type
* Word64 -- time (nanosecs)
* [Word16] -- length of the rest (for variable-sized events only)
* ... extra event-specific info ...
*
*
* To add a new event
* ------------------
*
* - In this file:
* - give it a new number, add a new #define EVENT_XXX below
* - In EventLog.c
* - add it to the EventDesc array
* - emit the event type in initEventLogging()
* - emit the new event in postEvent_()
* - generate the event itself by calling postEvent() somewhere
* - In the Haskell code to parse the event log file:
* - add types and code to read the new event
*
* -------------------------------------------------------------------------- */
/*
* Markers for begin/end of the Header.
*/
#define EVENT_HEADER_BEGIN 0x68647262 /* 'h' 'd' 'r' 'b' */
#define EVENT_HEADER_END 0x68647265 /* 'h' 'd' 'r' 'e' */
#define EVENT_DATA_BEGIN 0x64617462 /* 'd' 'a' 't' 'b' */
#define EVENT_DATA_END 0xffff
/*
* Markers for begin/end of the list of Event Types in the Header.
* Header, Event Type, Begin = hetb
* Header, Event Type, End = hete
*/
#define EVENT_HET_BEGIN 0x68657462 /* 'h' 'e' 't' 'b' */
#define EVENT_HET_END 0x68657465 /* 'h' 'e' 't' 'e' */
#define EVENT_ET_BEGIN 0x65746200 /* 'e' 't' 'b' 0 */
#define EVENT_ET_END 0x65746500 /* 'e' 't' 'e' 0 */
/*
* Types of event
*/
#define EVENT_CREATE_THREAD 0 /* (cap, thread) */
#define EVENT_RUN_THREAD 1 /* (cap, thread) */
#define EVENT_STOP_THREAD 2 /* (cap, thread, status) */
#define EVENT_THREAD_RUNNABLE 3 /* (cap, thread) */
#define EVENT_MIGRATE_THREAD 4 /* (cap, thread, new_cap) */
#define EVENT_RUN_SPARK 5 /* (cap, thread) */
#define EVENT_STEAL_SPARK 6 /* (cap, thread, victim_cap) */
#define EVENT_SHUTDOWN 7 /* (cap) */
#define EVENT_THREAD_WAKEUP 8 /* (cap, thread, other_cap) */
#define EVENT_GC_START 9 /* (cap) */
#define EVENT_GC_END 10 /* (cap) */
#define EVENT_REQUEST_SEQ_GC 11 /* (cap) */
#define EVENT_REQUEST_PAR_GC 12 /* (cap) */
#define NUM_EVENT_TAGS 13
/*
* Status values for EVENT_STOP_THREAD
*
* 1-5 are the StgRun return values (from includes/Constants.h):
*
* #define HeapOverflow 1
* #define StackOverflow 2
* #define ThreadYielding 3
* #define ThreadBlocked 4
* #define ThreadFinished 5
*/
#define THREAD_SUSPENDED_FOREIGN_CALL 6
#ifndef EVENTLOG_CONSTANTS_ONLY
typedef StgWord16 EventTypeNum;
typedef StgWord64 Timestamp; // in nanoseconds
typedef StgWord64 ThreadID;
typedef StgWord16 CapabilityNum;
#endif
......@@ -60,6 +60,7 @@ struct DEBUG_FLAGS {
rtsBool sanity; /* 'S' warning: might be expensive! */
rtsBool stable; /* 't' */
rtsBool prof; /* 'p' */
rtsBool eventlog; /* 'e' */
rtsBool gran; /* 'r' */
rtsBool par; /* 'P' */
rtsBool linker; /* 'l' the object linker */
......@@ -67,6 +68,7 @@ struct DEBUG_FLAGS {
rtsBool stm; /* 'm' */
rtsBool squeeze; /* 'z' stack squeezing & lazy blackholing */
rtsBool hpc; /* 'c' coverage */
rtsBool timestamp; /* add timestamps to traces */
};
struct COST_CENTRE_FLAGS {
......@@ -113,6 +115,12 @@ struct PROFILING_FLAGS {
};
#ifdef EVENTLOG
struct EVENTLOG_FLAGS {
rtsBool doEventLogging;
};
#endif
struct CONCURRENT_FLAGS {
int ctxtSwitchTime; /* in milliseconds */
int ctxtSwitchTicks; /* derived */
......@@ -307,12 +315,6 @@ struct TICKY_FLAGS {
FILE *tickyFile;
};
struct TRACE_FLAGS {
rtsBool sched; /* trace scheduler events for profiling */
rtsBool gc; /* trace GC events */
rtsBool timestamp; /* add timestamps to traces */
};
#ifdef USE_PAPI
#define MAX_PAPI_USER_EVENTS 8
......@@ -341,8 +343,10 @@ typedef struct _RTS_FLAGS {
struct DEBUG_FLAGS DebugFlags;
struct COST_CENTRE_FLAGS CcFlags;
struct PROFILING_FLAGS ProfFlags;
#ifdef EVENTLOG
struct EVENTLOG_FLAGS EventLogFlags;
#endif
struct TICKY_FLAGS TickyFlags;
struct TRACE_FLAGS TraceFlags;
#if defined(THREADED_RTS) || defined(PAR)
struct PAR_FLAGS ParFlags;
......
......@@ -385,8 +385,11 @@ endif
# thr_debug_p : debugging threaded profiled
# t : ticky-ticky profiling
# debug_t : debugging ticky-ticky profiling
# l : event logging
# thr_l : threaded and event logging
# thr_debug_l : threaded and debugging and event logging
#
GhcRTSWays=
GhcRTSWays=l
# Usually want the debug version
ifeq "$(BootingFromHc)" "NO"
......@@ -400,7 +403,8 @@ endif
# Want the threaded versions unless we're unregisterised
# Defer the check until later by using $(if..), because GhcUnregisterised might
# be set in build.mk, which hasn't been read yet.
GhcRTSWays += $(if $(findstring NO, $(GhcUnregisterised)),thr thr_p thr_debug,)
GhcRTSWays += $(if $(findstring NO, $(GhcUnregisterised)),thr thr_debug thr_l,)
GhcRTSWays += $(if $(findstring p, $(GhcLibWays)),thr_p,)
# We can only build GHCi threaded if we have a threaded RTS:
GhcThreaded = $(if $(findstring thr,$(GhcRTSWays)),YES,NO)
......@@ -1248,6 +1252,10 @@ WAY_p_HC_OPTS= -prof
WAY_t_NAME=ticky-ticky profiling
WAY_t_HC_OPTS= -ticky
# Way 'l':
WAY_l_NAME=event logging
WAY_l_HC_OPTS= -eventlog
# Way `mp':
WAY_mp_NAME=parallel
WAY_mp_HC_OPTS=-parallel
......@@ -1268,6 +1276,10 @@ WAY_thr_HC_OPTS=-optc-DTHREADED_RTS
WAY_thr_p_NAME=threaded profiled
WAY_thr_p_HC_OPTS=-optc-DTHREADED_RTS -prof
# Way 'thr_l':
WAY_thr_l_NAME=threaded event logging
WAY_thr_l_HC_OPTS=-optc-DTHREADED_RTS -eventlog
# Way 'debug':
WAY_debug_NAME=debug
WAY_debug_HC_OPTS=-optc-DDEBUG
......@@ -1288,6 +1300,10 @@ WAY_thr_debug_HC_OPTS=-optc-DTHREADED_RTS -optc-DDEBUG
WAY_thr_debug_p_NAME=threaded debug profiling
WAY_thr_debug_p_HC_OPTS=-optc-DTHREADED_RTS -optc-DDEBUG -prof
# Way 'thr_debug_l':
WAY_thr_debug_l_NAME=threaded debug event logging
WAY_thr_debug_l_HC_OPTS=-optc-DTHREADED_RTS -optc-DDEBUG -eventlog
# Way 'dyn': build dynamic shared libraries
WAY_dyn_NAME=dyn
WAY_dyn_HC_OPTS=-fPIC -dynamic
......
......@@ -320,10 +320,9 @@ giveCapabilityToTask (Capability *cap USED_IF_DEBUG, Task *task)
{
ASSERT_LOCK_HELD(&cap->lock);
ASSERT(task->cap == cap);
trace(TRACE_sched | DEBUG_sched,
"passing capability %d to %s %p",
cap->no, task->tso ? "bound task" : "worker",
(void *)task->id);
debugTrace(DEBUG_sched, "passing capability %d to %s %p",
cap->no, task->tso ? "bound task" : "worker",
(void *)task->id);
ACQUIRE_LOCK(&task->lock);
task->wakeup = rtsTrue;
// the wakeup flag is needed because signalCondition() doesn't
......@@ -365,8 +364,7 @@ releaseCapability_ (Capability* cap,
if (waiting_for_gc == PENDING_GC_SEQ) {
last_free_capability = cap; // needed?
trace(TRACE_sched | DEBUG_sched,
"GC pending, set capability %d free", cap->no);
debugTrace(DEBUG_sched, "GC pending, set capability %d free", cap->no);
return;
}
......@@ -407,7 +405,7 @@ releaseCapability_ (Capability* cap,
}
last_free_capability = cap;
trace(TRACE_sched | DEBUG_sched, "freeing capability %d", cap->no);
debugTrace(DEBUG_sched, "freeing capability %d", cap->no);
}
void
......@@ -542,7 +540,7 @@ waitForReturnCapability (Capability **pCap, Task *task)
ASSERT_FULL_CAPABILITY_INVARIANTS(cap,task);
trace(TRACE_sched | DEBUG_sched, "resuming capability %d", cap->no);
debugTrace(DEBUG_sched, "resuming capability %d", cap->no);
*pCap = cap;
#endif
......@@ -560,7 +558,9 @@ yieldCapability (Capability** pCap, Task *task)
if (waiting_for_gc == PENDING_GC_PAR) {
debugTrace(DEBUG_sched, "capability %d: becoming a GC thread", cap->no);
postEvent(cap, EVENT_GC_START, 0, 0);
gcWorkerThread(cap);
postEvent(cap, EVENT_GC_END, 0, 0);
return;
}
......@@ -606,7 +606,7 @@ yieldCapability (Capability** pCap, Task *task)
break;
}
trace(TRACE_sched | DEBUG_sched, "resuming capability %d", cap->no);
debugTrace(DEBUG_sched, "resuming capability %d", cap->no);
ASSERT(cap->running_task == task);
*pCap = cap;
......@@ -648,7 +648,6 @@ wakeupThreadOnCapability (Capability *my_cap,
appendToRunQueue(other_cap,tso);
trace(TRACE_sched, "resuming capability %d", other_cap->no);
releaseCapability_(other_cap,rtsFalse);
} else {
appendToWakeupQueue(my_cap,other_cap,tso);
......@@ -768,6 +767,7 @@ shutdownCapability (Capability *cap, Task *task, rtsBool safe)
continue;
}
postEvent(cap, EVENT_SHUTDOWN, 0, 0);
debugTrace(DEBUG_sched, "capability %d is stopped.", cap->no);
RELEASE_LOCK(&cap->lock);
break;
......
......@@ -57,7 +57,7 @@ override HADDOCK_DOCS = NO
NON_HS_PACKAGE = YES
# grab sources from these subdirectories
ALL_DIRS = hooks parallel sm
ALL_DIRS = hooks parallel sm eventlog
ifeq "$(HOSTPLATFORM)" "i386-unknown-mingw32"
ALL_DIRS += win32
......@@ -137,7 +137,8 @@ WARNING_OPTS += -Waggregate-return
#WARNING_OPTS += -Wredundant-decls
#WARNING_OPTS += -Wconversion
STANDARD_OPTS += -I../includes -I. -Iparallel -Ism
STANDARD_OPTS += -I../includes -I. -Iparallel -Ism -Ieventlog
# COMPILING_RTS is only used when building Win32 DLL support.
STANDARD_OPTS += -DCOMPILING_RTS
......@@ -322,7 +323,7 @@ SRC_MKDEPENDC_OPTS += -I. -I../includes
# a superset of the dependencies. To do this properly, we should generate
# a different set of dependencies for each way. Further hack: PROFILING and
# TICKY_TICKY can't be used together, so we omit TICKY_TICKY for now.
SRC_MKDEPENDC_OPTS += -DPROFILING -DTHREADED_RTS -DDEBUG
SRC_MKDEPENDC_OPTS += -DPROFILING -DTHREADED_RTS -DDEBUG -DEVENTLOG
# -----------------------------------------------------------------------------
# The auto-generated apply code
......
......@@ -18,6 +18,7 @@
#include "STM.h"
#include "Sanity.h"
#include "Profiling.h"
#include "EventLog.h"
#if defined(mingw32_HOST_OS)
#include "win32/IOManager.h"
#endif
......
......@@ -184,12 +184,14 @@ void initRtsFlagsDefaults(void)
RtsFlags.DebugFlags.stable = rtsFalse;
RtsFlags.DebugFlags.stm = rtsFalse;
RtsFlags.DebugFlags.prof = rtsFalse;
RtsFlags.DebugFlags.eventlog = rtsFalse;
RtsFlags.DebugFlags.gran = rtsFalse;
RtsFlags.DebugFlags.par = rtsFalse;
RtsFlags.DebugFlags.apply = rtsFalse;
RtsFlags.DebugFlags.linker = rtsFalse;
RtsFlags.DebugFlags.squeeze = rtsFalse;
RtsFlags.DebugFlags.hpc = rtsFalse;
RtsFlags.DebugFlags.timestamp = rtsFalse;
#endif
#if defined(PROFILING) || defined(PAR)
......@@ -213,6 +215,10 @@ void initRtsFlagsDefaults(void)
RtsFlags.ProfFlags.bioSelector = NULL;
#endif
#ifdef EVENTLOG
RtsFlags.EventLogFlags.doEventLogging = rtsFalse;
#endif
RtsFlags.MiscFlags.tickInterval = 20; /* In milliseconds */
RtsFlags.ConcFlags.ctxtSwitchTime = 20; /* In milliseconds */
......@@ -329,10 +335,6 @@ void initRtsFlagsDefaults(void)
RtsFlags.TickyFlags.tickyFile = NULL;
#endif
RtsFlags.TraceFlags.timestamp = rtsFalse;
RtsFlags.TraceFlags.sched = rtsFalse;
RtsFlags.TraceFlags.gc = rtsFalse;
#ifdef USE_PAPI
/* By default no special measurements taken */
RtsFlags.PapiFlags.eventType = 0;
......@@ -419,6 +421,13 @@ usage_text[] = {
"",
# endif
#endif /* PROFILING or PAR */
#ifdef EVENTLOG
"",
" -l Log runtime events (generates binary trace file <program>.eventlog)",
"",
#endif
#if !defined(PROFILING)
"",
" -hT Heap residency profile (output file <program>.hp)",
......@@ -440,8 +449,7 @@ usage_text[] = {
" This sets the resolution for -C and the profile timer -i.",
" Default: 0.02 sec.",
"",
" -vs Trace scheduler events (see also -Ds with -debug)",
" -vt Time-stamp trace messages",
" -vt Time-stamp debug messages",
"",
#if defined(DEBUG)
" -Ds DEBUG: scheduler",
......@@ -453,6 +461,7 @@ usage_text[] = {
" -DS DEBUG: sanity",
" -Dt DEBUG: stable",
" -Dp DEBUG: prof",
" -De DEBUG: event logging",
" -Dr DEBUG: gran",
" -DP DEBUG: par",
" -Da DEBUG: apply",
......@@ -660,6 +669,14 @@ errorBelch("not built for: -prof"); \
error = rtsTrue;
#endif
#ifdef EVENTLOG
# define EVENTLOG_BUILD_ONLY(x) x
#else
# define EVENTLOG_BUILD_ONLY(x) \
errorBelch("not built for: -par-prof"); \
error = rtsTrue;
#endif
#ifdef PAR
# define PAR_BUILD_ONLY(x) x
#else
......@@ -821,6 +838,9 @@ error = rtsTrue;
case 'p':
RtsFlags.DebugFlags.prof = rtsTrue;
break;
case 'e':
RtsFlags.DebugFlags.eventlog = rtsTrue;
break;
case 'r':
RtsFlags.DebugFlags.gran = rtsTrue;
break;
......@@ -955,6 +975,14 @@ error = rtsTrue;
/* =========== PROFILING ========================== */
case 'l':
#ifdef EVENTLOG
RtsFlags.EventLogFlags.doEventLogging = rtsTrue;
#else
errorBelch("not built for: -eventlog");
#endif
break;
case 'P': /* detailed cost centre profiling (time/alloc) */
case 'p': /* cost centre profiling (time/alloc) */
COST_CENTRE_USING_BUILD_ONLY(
......@@ -1270,13 +1298,11 @@ error = rtsTrue;
error = rtsTrue;
break;
case 't':
RtsFlags.TraceFlags.timestamp = rtsTrue;
RtsFlags.DebugFlags.timestamp = rtsTrue;
break;
case 's':
RtsFlags.TraceFlags.sched = rtsTrue;
break;
case 'g':
RtsFlags.TraceFlags.gc = rtsTrue;
// ignored for backwards-compat
break;
default:
errorBelch("unknown RTS option: %s",rts_argv[arg]);
......
......@@ -34,6 +34,7 @@
#include "Stable.h"
#include "Hpc.h"
#include "FileLock.h"
#include "EventLog.h"
#if defined(RTS_GTK_FRONTPANEL)
#include "FrontPanel.h"
......@@ -195,7 +196,9 @@ hs_init(int *argc, char **argv[])
#endif
/* initTracing must be after setupRtsFlags() */
#ifdef DEBUG
initTracing();
#endif
#if defined(PAR)
/* NB: this really must be done after processing the RTS flags */
......@@ -254,6 +257,12 @@ hs_init(int *argc, char **argv[])
initProfiling1();
#ifdef EVENTLOG
if (RtsFlags.EventLogFlags.doEventLogging) {
initEventLogging();
}
#endif
/* start the virtual timer 'subsystem'. */
initTimer();
startTimer();
......@@ -514,6 +523,13 @@ hs_exit_(rtsBool wait_foreign)
if (prof_file != NULL) fclose(prof_file);
#endif
#ifdef EVENTLOG
if (RtsFlags.EventLogFlags.doEventLogging) {
endEventLogging();
freeEventLogging();
}
#endif
#if defined(TICKY_TICKY)
if (RtsFlags.TickyFlags.showTickyStats) PrintTickyInfo();
#endif
......
......@@ -33,6 +33,7 @@
#include "ProfHeap.h"
#include "GC.h"
#include "Weak.h"
#include "EventLog.h"
/* PARALLEL_HASKELL includes go here */
......@@ -539,6 +540,8 @@ run_thread:
}
#endif
postEvent(cap, EVENT_RUN_THREAD, t->id, 0);
switch (prev_what_next) {
case ThreadKilled:
......@@ -587,6 +590,8 @@ run_thread:
t->saved_winerror = GetLastError();
#endif
postEvent (cap, EVENT_STOP_THREAD, t->id, ret);
#if defined(THREADED_RTS)
// If ret is ThreadBlocked, and this Task is bound to the TSO that
// blocked, we are in limbo - the TSO is now owned by whatever it
......@@ -852,6 +857,9 @@ schedulePushWork(Capability *cap USED_IF_THREADS,
} else {
debugTrace(DEBUG_sched, "pushing thread %lu to capability %d", (unsigned long)t->id, free_caps[i]->no);
appendToRunQueue(free_caps[i],t);
postEvent (cap, EVENT_MIGRATE_THREAD, t->id, free_caps[i]->no);
if (t->bound) { t->bound->cap = free_caps[i]; }
t->cap = free_caps[i];
i++;
......@@ -1560,6 +1568,7 @@ scheduleDoGC (Capability *cap, Task *task USED_IF_THREADS, rtsBool force_major)
if (gc_type == PENDING_GC_SEQ)
{
postEvent(cap, EVENT_REQUEST_SEQ_GC, 0, 0);
// single-threaded GC: grab all the capabilities
for (i=0; i < n_capabilities; i++) {
debugTrace(DEBUG_sched, "ready_to_gc, grabbing all the capabilies (%d/%d)", i, n_capabilities);
......@@ -1582,6 +1591,7 @@ scheduleDoGC (Capability *cap, Task *task USED_IF_THREADS, rtsBool force_major)
{
// multi-threaded GC: make sure all the Capabilities donate one
// GC thread each.
postEvent(cap, EVENT_REQUEST_PAR_GC, 0, 0);
debugTrace(DEBUG_sched, "ready_to_gc, grabbing GC threads");
waitForGcThreads(cap);
......@@ -1607,6 +1617,7 @@ delete_threads_and_gc:
heap_census = scheduleNeedHeapProfile(rtsTrue);
#if defined(THREADED_RTS)
postEvent(cap, EVENT_GC_START, 0, 0);
debugTrace(DEBUG_sched, "doing GC");
// reset waiting_for_gc *before* GC, so that when the GC threads
// emerge they don't immediately re-enter the GC.
......@@ -1615,6 +1626,7 @@ delete_threads_and_gc:
#else
GarbageCollect(force_major || heap_census, 0, cap);
#endif
postEvent(cap, EVENT_GC_END, 0, 0);
if (recent_activity == ACTIVITY_INACTIVE && force_major)
{
......@@ -1930,6 +1942,7 @@ suspendThread (StgRegTable *reg)
task = cap->running_task;
tso = cap->r.rCurrentTSO;
postEvent(cap, EVENT_STOP_THREAD, tso->id, THREAD_SUSPENDED_FOREIGN_CALL);
debugTrace(DEBUG_sched,
"thread %lu did a safe foreign call",
(unsigned long)cap->r.rCurrentTSO->id);
......@@ -2001,6 +2014,8 @@ resumeThread (void *task_)
tso = task->suspended_tso;
task->suspended_tso = NULL;
tso->_link = END_TSO_QUEUE; // no write barrier reqd
postEvent(cap, EVENT_RUN_THREAD, tso->id, 0);
debugTrace(DEBUG_sched, "thread %lu: re-entering RTS", (unsigned long)tso->id);
if (tso->why_blocked == BlockedOnCCall) {
......@@ -2057,6 +2072,7 @@ scheduleThreadOn(Capability *cap, StgWord cpu USED_IF_THREADS, StgTSO *tso)
if (cpu == cap->no) {
appendToRunQueue(cap,tso);
} else {
postEvent (cap, EVENT_MIGRATE_THREAD, tso->id, capabilities[cpu].no);
wakeupThreadOnCapability(cap, &capabilities[cpu], tso);
}
#else
......@@ -2196,8 +2212,6 @@ initScheduler(void)
}
#endif
trace(TRACE_sched, "start: %d capabilities", n_capabilities);
RELEASE_LOCK(&sched_mutex);
}
......
......@@ -12,6 +12,7 @@
#include "OSThreads.h"
#include "Capability.h"
#include "EventLog.h"
/* initScheduler(), exitScheduler()
* Called from STG : no
......@@ -188,10 +189,10 @@ appendToRunQueue (Capability *cap, StgTSO *tso)
setTSOLink(cap, cap->run_queue_tl, tso);
}
cap->run_queue_tl = tso;
postEvent (cap, EVENT_THREAD_RUNNABLE, tso->id, 0);
}
/* Push a thread on the beginning of the run queue. Used for
* newly awakened threads, so they get run as soon as possible.
/* Push a thread on the beginning of the run queue.
* ASSUMES: cap->running_task is the current task.
*/
INLINE_HEADER void
......
......@@ -210,6 +210,8 @@ createThread(Capability *cap, nat size)
}
#endif
postEvent (cap, EVENT_CREATE_THREAD, tso->id, 0);
#if defined(GRAN)
debugTrace(GRAN_DEBUG_pri,
"==__ schedule: Created TSO %d (%p);",
......@@ -503,6 +505,7 @@ unblockOne_ (Capability *cap, StgTSO *tso,
ASSERT(tso->bound->cap == tso->cap);
tso->bound->cap = cap;
}
tso->cap = cap;
appendToRunQueue(cap,tso);
......@@ -523,8 +526,9 @@ unblockOne_ (Capability *cap, StgTSO *tso,
cap->context_switch = 1;
#endif
debugTrace(DEBUG_sched,
"waking up thread %ld on cap %d",
postEvent (cap, EVENT_THREAD_WAKEUP, tso->id, tso->cap->no);
debugTrace(DEBUG_sched, "waking up thread %ld on cap %d",
(long)tso->id, tso->cap->no);
return next;
......
/* -----------------------------------------------------------------------------
*
* (c) The GHC Team 2006
* (c) The GHC Team 2006-2009
*
* Debug and performance tracing
*
* ---------------------------------------------------------------------------*/
#ifdef DEBUG
#include "Rts.h"
#include "OSThreads.h"
#include "Trace.h"
......@@ -28,33 +30,8 @@ StgWord32 classes_enabled; // not static due to inline funcs
static Mutex trace_utx;
#endif
#ifdef DEBUG
#define DEBUG_FLAG(name, class) \
if (RtsFlags.DebugFlags.name) classes_enabled |= class;
#else
#define DEBUG_FLAG(name, class) \
/* nothing */
#endif
#ifdef PAR
#define PAR_FLAG(name, class) \
if (RtsFlags.ParFlags.Debug.name) classes_enabled |= class;
#else
#define PAR_FLAG(name, class) \
/* nothing */
#endif
#ifdef GRAN
#define GRAN_FLAG(name, class) \
if (RtsFlags.GranFlags.Debug.name) classes_enabled |= class;
#else
#define GRAN_FLAG(name, class) \
/* nothing */
#endif
#define TRACE_FLAG(name, class) \
if (RtsFlags.TraceFlags.name) classes_enabled |= class;
void initTracing (void)
{
......@@ -72,43 +49,12 @@ void initTracing (void)
DEBUG_FLAG(stable, DEBUG_stable);
DEBUG_FLAG(stm, DEBUG_stm);
DEBUG_FLAG(prof, DEBUG_prof);
DEBUG_FLAG(eventlog, DEBUG_eventlog);
DEBUG_FLAG(gran, DEBUG_gran);