EventLog.c 44 KB
Newer Older
Simon Marlow's avatar
Simon Marlow committed
1 2 3 4 5 6 7 8
/* -----------------------------------------------------------------------------
 *
 * (c) The GHC Team, 2008-2009
 *
 * Support for fast binary event logging.
 *
 * ---------------------------------------------------------------------------*/

Simon Marlow's avatar
Simon Marlow committed
9
#include "PosixSource.h"
Simon Marlow's avatar
Simon Marlow committed
10
#include "Rts.h"
Simon Marlow's avatar
Simon Marlow committed
11

Ben Gamari's avatar
Ben Gamari committed
12
#if defined(TRACING)
13 14

#include "Trace.h"
Simon Marlow's avatar
Simon Marlow committed
15 16 17
#include "Capability.h"
#include "RtsUtils.h"
#include "Stats.h"
18
#include "EventLog.h"
Simon Marlow's avatar
Simon Marlow committed
19

20
#include <string.h>
Simon Marlow's avatar
Simon Marlow committed
21
#include <stdio.h>
Ben Gamari's avatar
Ben Gamari committed
22
#if defined(HAVE_SYS_TYPES_H)
23 24
#include <sys/types.h>
#endif
Ben Gamari's avatar
Ben Gamari committed
25
#if defined(HAVE_UNISTD_H)
26 27 28
#include <unistd.h>
#endif

29
static const EventLogWriter *event_log_writer;
Simon Marlow's avatar
Simon Marlow committed
30 31 32 33 34 35 36 37 38

#define EVENT_LOG_SIZE 2 * (1024 * 1024) // 2MB

static int flushCount;

// Struct for record keeping of buffer to store event types and events.
typedef struct _EventsBuf {
  StgInt8 *begin;
  StgInt8 *pos;
Simon Marlow's avatar
Simon Marlow committed
39
  StgInt8 *marker;
Simon Marlow's avatar
Simon Marlow committed
40
  StgWord64 size;
41
  EventCapNo capno; // which capability this buffer belongs to, or -1
Simon Marlow's avatar
Simon Marlow committed
42 43
} EventsBuf;

44 45 46
EventsBuf *capEventBuf; // one EventsBuf for each Capability

EventsBuf eventBuf; // an EventsBuf not associated with any Capability
Ben Gamari's avatar
Ben Gamari committed
47
#if defined(THREADED_RTS)
48 49
Mutex eventBufMutex; // protected by this mutex
#endif
Simon Marlow's avatar
Simon Marlow committed
50 51

char *EventDesc[] = {
52 53 54 55 56 57
  [EVENT_CREATE_THREAD]       = "Create thread",
  [EVENT_RUN_THREAD]          = "Run thread",
  [EVENT_STOP_THREAD]         = "Stop thread",
  [EVENT_THREAD_RUNNABLE]     = "Thread runnable",
  [EVENT_MIGRATE_THREAD]      = "Migrate thread",
  [EVENT_THREAD_WAKEUP]       = "Wakeup thread",
58
  [EVENT_THREAD_LABEL]        = "Thread label",
59 60 61 62
  [EVENT_CAP_CREATE]          = "Create capability",
  [EVENT_CAP_DELETE]          = "Delete capability",
  [EVENT_CAP_DISABLE]         = "Disable capability",
  [EVENT_CAP_ENABLE]          = "Enable capability",
63 64 65 66
  [EVENT_GC_START]            = "Starting GC",
  [EVENT_GC_END]              = "Finished GC",
  [EVENT_REQUEST_SEQ_GC]      = "Request sequential GC",
  [EVENT_REQUEST_PAR_GC]      = "Request parallel GC",
67
  [EVENT_GC_GLOBAL_SYNC]      = "Synchronise stop-the-world GC",
68 69 70 71 72
  [EVENT_GC_STATS_GHC]        = "GC statistics",
  [EVENT_HEAP_INFO_GHC]       = "Heap static parameters",
  [EVENT_HEAP_ALLOCATED]      = "Total heap mem ever allocated",
  [EVENT_HEAP_SIZE]           = "Current heap size",
  [EVENT_HEAP_LIVE]           = "Current heap live data",
73 74
  [EVENT_CREATE_SPARK_THREAD] = "Create spark thread",
  [EVENT_LOG_MSG]             = "Log message",
75
  [EVENT_USER_MSG]            = "User message",
76
  [EVENT_USER_MARKER]         = "User marker",
77 78 79
  [EVENT_GC_IDLE]             = "GC idle",
  [EVENT_GC_WORK]             = "GC working",
  [EVENT_GC_DONE]             = "GC done",
80 81 82 83
  [EVENT_BLOCK_MARKER]        = "Block marker",
  [EVENT_CAPSET_CREATE]       = "Create capability set",
  [EVENT_CAPSET_DELETE]       = "Delete capability set",
  [EVENT_CAPSET_ASSIGN_CAP]   = "Add capability to capability set",
84 85 86 87 88
  [EVENT_CAPSET_REMOVE_CAP]   = "Remove capability from capability set",
  [EVENT_RTS_IDENTIFIER]      = "RTS name and version",
  [EVENT_PROGRAM_ARGS]        = "Program arguments",
  [EVENT_PROGRAM_ENV]         = "Program environment variables",
  [EVENT_OSPROCESS_PID]       = "Process ID",
Duncan Coutts's avatar
Duncan Coutts committed
89
  [EVENT_OSPROCESS_PPID]      = "Parent process ID",
90
  [EVENT_WALL_CLOCK_TIME]     = "Wall clock time",
91 92 93 94 95 96 97 98
  [EVENT_SPARK_COUNTERS]      = "Spark counters",
  [EVENT_SPARK_CREATE]        = "Spark create",
  [EVENT_SPARK_DUD]           = "Spark dud",
  [EVENT_SPARK_OVERFLOW]      = "Spark overflow",
  [EVENT_SPARK_RUN]           = "Spark run",
  [EVENT_SPARK_STEAL]         = "Spark steal",
  [EVENT_SPARK_FIZZLE]        = "Spark fizzle",
  [EVENT_SPARK_GC]            = "Spark GC",
99 100 101
  [EVENT_TASK_CREATE]         = "Task create",
  [EVENT_TASK_MIGRATE]        = "Task migrate",
  [EVENT_TASK_DELETE]         = "Task delete",
102
  [EVENT_HACK_BUG_T9003]      = "Empty event for bug #9003",
103 104 105
  [EVENT_HEAP_PROF_BEGIN]     = "Start of heap profile",
  [EVENT_HEAP_PROF_COST_CENTRE]   = "Cost center definition",
  [EVENT_HEAP_PROF_SAMPLE_BEGIN]  = "Start of heap profile sample",
106
  [EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN]  = "Start of heap profile (biographical) sample",
107
  [EVENT_HEAP_PROF_SAMPLE_END]    = "End of heap profile sample",
108 109
  [EVENT_HEAP_PROF_SAMPLE_STRING] = "Heap profile string sample",
  [EVENT_HEAP_PROF_SAMPLE_COST_CENTRE] = "Heap profile cost-centre sample",
110 111 112 113 114 115 116
  [EVENT_USER_BINARY_MSG]     = "User binary message",
  [EVENT_CONC_MARK_BEGIN]        = "Begin concurrent mark phase",
  [EVENT_CONC_MARK_END]          = "End concurrent mark phase",
  [EVENT_CONC_SYNC_BEGIN]        = "Begin concurrent GC synchronisation",
  [EVENT_CONC_SYNC_END]          = "End concurrent GC synchronisation",
  [EVENT_CONC_SWEEP_BEGIN]       = "Begin concurrent sweep",
  [EVENT_CONC_SWEEP_END]         = "End concurrent sweep",
117 118
  [EVENT_CONC_UPD_REM_SET_FLUSH] = "Update remembered set flushed",
  [EVENT_NONMOVING_HEAP_CENSUS]  = "Nonmoving heap census"
Simon Marlow's avatar
Simon Marlow committed
119 120
};

121
// Event type.
Simon Marlow's avatar
Simon Marlow committed
122 123 124

typedef struct _EventType {
  EventTypeNum etNum;  // Event Type number.
125
  uint32_t   size;     // size of the payload in bytes
Simon Marlow's avatar
Simon Marlow committed
126 127 128
  char *desc;     // Description
} EventType;

129
EventType eventTypes[NUM_GHC_EVENT_TAGS];
Simon Marlow's avatar
Simon Marlow committed
130

131
static void initEventsBuf(EventsBuf* eb, StgWord64 size, EventCapNo capno);
Simon Marlow's avatar
Simon Marlow committed
132
static void resetEventsBuf(EventsBuf* eb);
Simon Marlow's avatar
Simon Marlow committed
133
static void printAndClearEventBuf (EventsBuf *eventsBuf);
Simon Marlow's avatar
Simon Marlow committed
134 135 136

static void postEventType(EventsBuf *eb, EventType *et);

137
static void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap);
138

Simon Marlow's avatar
Simon Marlow committed
139 140 141
static void postBlockMarker(EventsBuf *eb);
static void closeBlockMarker(EventsBuf *ebuf);

Simon Marlow's avatar
Simon Marlow committed
142
static StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum);
143
static StgBool hasRoomForVariableEvent(EventsBuf *eb, uint32_t payload_bytes);
Simon Marlow's avatar
Simon Marlow committed
144

145 146 147
static void ensureRoomForEvent(EventsBuf *eb, EventTypeNum tag);
static int ensureRoomForVariableEvent(EventsBuf *eb, StgWord16 size);

148 149
static inline void postWord8(EventsBuf *eb, StgWord8 i)
{
150
    *(eb->pos++) = i;
151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170
}

static inline void postWord16(EventsBuf *eb, StgWord16 i)
{
    postWord8(eb, (StgWord8)(i >> 8));
    postWord8(eb, (StgWord8)i);
}

static inline void postWord32(EventsBuf *eb, StgWord32 i)
{
    postWord16(eb, (StgWord16)(i >> 16));
    postWord16(eb, (StgWord16)i);
}

static inline void postWord64(EventsBuf *eb, StgWord64 i)
{
    postWord32(eb, (StgWord32)(i >> 32));
    postWord32(eb, (StgWord32)i);
}

171
static inline void postBuf(EventsBuf *eb, StgWord8 *buf, uint32_t size)
172 173 174 175 176
{
    memcpy(eb->pos, buf, size);
    eb->pos += size;
}

177 178 179 180 181 182 183
/* Post a null-terminated string to the event log.
 * It is the caller's responsibility to ensure that there is
 * enough room for strlen(buf)+1 bytes.
 */
static inline void postString(EventsBuf *eb, const char *buf)
{
    if (buf) {
184
        const int len = strlen(buf);
185 186 187 188 189 190 191 192
        ASSERT(eb->begin + eb->size > eb->pos + len);
        memcpy(eb->pos, buf, len);
        eb->pos += len;
    }
    *eb->pos = 0;
    eb->pos++;
}

Simon Marlow's avatar
Simon Marlow committed
193
static inline StgWord64 time_ns(void)
Simon Marlow's avatar
Simon Marlow committed
194
{ return TimeToNS(stat_getElapsedTime()); }
Simon Marlow's avatar
Simon Marlow committed
195

196 197 198
static inline void postEventTypeNum(EventsBuf *eb, EventTypeNum etNum)
{ postWord16(eb, etNum); }

Simon Marlow's avatar
Simon Marlow committed
199 200
static inline void postTimestamp(EventsBuf *eb)
{ postWord64(eb, time_ns()); }
201

202
static inline void postThreadID(EventsBuf *eb, EventThreadID id)
203 204
{ postWord32(eb,id); }

205
static inline void postCapNo(EventsBuf *eb, EventCapNo no)
206 207
{ postWord16(eb,no); }

208 209 210 211 212 213
static inline void postCapsetID(EventsBuf *eb, EventCapsetID id)
{ postWord32(eb,id); }

static inline void postCapsetType(EventsBuf *eb, EventCapsetType type)
{ postWord16(eb,type); }

214 215 216 217 218 219 220 221 222
static inline void postOSProcessId(EventsBuf *eb, pid_t pid)
{ postWord32(eb, pid); }

static inline void postKernelThreadId(EventsBuf *eb, EventKernelThreadId tid)
{ postWord64(eb, tid); }

static inline void postTaskId(EventsBuf *eb, EventTaskId tUniq)
{ postWord64(eb, tUniq); }

223 224 225
static inline void postPayloadSize(EventsBuf *eb, EventPayloadSize size)
{ postWord16(eb,size); }

Simon Marlow's avatar
Simon Marlow committed
226 227 228 229
static inline void postEventHeader(EventsBuf *eb, EventTypeNum type)
{
    postEventTypeNum(eb, type);
    postTimestamp(eb);
230
}
Simon Marlow's avatar
Simon Marlow committed
231

232 233 234 235 236 237
static inline void postInt8(EventsBuf *eb, StgInt8 i)
{ postWord8(eb, (StgWord8)i); }

static inline void postInt32(EventsBuf *eb, StgInt32 i)
{ postWord32(eb, (StgWord32)i); }

238
#define EVENT_SIZE_DYNAMIC (-1)
Simon Marlow's avatar
Simon Marlow committed
239

240 241
static void
initEventLogWriter(void)
Simon Marlow's avatar
Simon Marlow committed
242
{
243 244 245
    if (event_log_writer != NULL &&
            event_log_writer->initEventLogWriter != NULL) {
        event_log_writer->initEventLogWriter();
246
    }
247
}
Simon Marlow's avatar
Simon Marlow committed
248

249 250 251 252 253 254 255 256 257 258
static bool
writeEventLog(void *eventlog, size_t eventlog_size)
{
    if (event_log_writer != NULL &&
            event_log_writer->writeEventLog != NULL) {
        return event_log_writer->writeEventLog(eventlog, eventlog_size);
    } else {
        return false;
    }
}
Simon Marlow's avatar
Simon Marlow committed
259

260 261 262 263 264 265
static void
stopEventLogWriter(void)
{
    if (event_log_writer != NULL &&
            event_log_writer->stopEventLogWriter != NULL) {
        event_log_writer->stopEventLogWriter();
Simon Marlow's avatar
Simon Marlow committed
266
    }
267
}
268

269 270 271 272 273 274
void
flushEventLog(void)
{
    if (event_log_writer != NULL &&
            event_log_writer->flushEventLog != NULL) {
        event_log_writer->flushEventLog();
275
    }
276 277
}

278
static void
279
init_event_types(void)
280
{
281
    for (int t = 0; t < NUM_GHC_EVENT_TAGS; ++t) {
Simon Marlow's avatar
Simon Marlow committed
282 283 284 285 286 287 288
        eventTypes[t].etNum = t;
        eventTypes[t].desc = EventDesc[t];

        switch (t) {
        case EVENT_CREATE_THREAD:   // (cap, thread)
        case EVENT_RUN_THREAD:      // (cap, thread)
        case EVENT_THREAD_RUNNABLE: // (cap, thread)
289
        case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
290
            eventTypes[t].size = sizeof(EventThreadID);
291 292
            break;

Simon Marlow's avatar
Simon Marlow committed
293 294 295
        case EVENT_MIGRATE_THREAD:  // (cap, thread, new_cap)
        case EVENT_THREAD_WAKEUP:   // (cap, thread, other_cap)
            eventTypes[t].size =
296
                sizeof(EventThreadID) + sizeof(EventCapNo);
Simon Marlow's avatar
Simon Marlow committed
297 298 299
            break;

        case EVENT_STOP_THREAD:     // (cap, thread, status)
300 301 302
            eventTypes[t].size = sizeof(EventThreadID)
                               + sizeof(StgWord16)
                               + sizeof(EventThreadID);
Simon Marlow's avatar
Simon Marlow committed
303 304
            break;

305 306 307 308
        case EVENT_CAP_CREATE:      // (cap)
        case EVENT_CAP_DELETE:      // (cap)
        case EVENT_CAP_ENABLE:      // (cap)
        case EVENT_CAP_DISABLE:     // (cap)
309 310 311
            eventTypes[t].size = sizeof(EventCapNo);
            break;

312 313 314 315 316 317 318 319 320 321 322 323 324 325 326
        case EVENT_CAPSET_CREATE:   // (capset, capset_type)
            eventTypes[t].size =
                sizeof(EventCapsetID) + sizeof(EventCapsetType);
            break;

        case EVENT_CAPSET_DELETE:   // (capset)
            eventTypes[t].size = sizeof(EventCapsetID);
            break;

        case EVENT_CAPSET_ASSIGN_CAP:  // (capset, cap)
        case EVENT_CAPSET_REMOVE_CAP:
            eventTypes[t].size =
                sizeof(EventCapsetID) + sizeof(EventCapNo);
            break;

327 328 329 330 331 332
        case EVENT_OSPROCESS_PID:   // (cap, pid)
        case EVENT_OSPROCESS_PPID:
            eventTypes[t].size =
                sizeof(EventCapsetID) + sizeof(StgWord32);
            break;

333 334 335 336 337
        case EVENT_WALL_CLOCK_TIME: // (capset, unix_epoch_seconds, nanoseconds)
            eventTypes[t].size =
                sizeof(EventCapsetID) + sizeof(StgWord64) + sizeof(StgWord32);
            break;

338 339 340 341 342
        case EVENT_SPARK_STEAL:     // (cap, victim_cap)
            eventTypes[t].size =
                sizeof(EventCapNo);
            break;

Simon Marlow's avatar
Simon Marlow committed
343 344 345 346
        case EVENT_REQUEST_SEQ_GC:  // (cap)
        case EVENT_REQUEST_PAR_GC:  // (cap)
        case EVENT_GC_START:        // (cap)
        case EVENT_GC_END:          // (cap)
347 348 349
        case EVENT_GC_IDLE:
        case EVENT_GC_WORK:
        case EVENT_GC_DONE:
350
        case EVENT_GC_GLOBAL_SYNC:  // (cap)
351 352 353 354 355 356
        case EVENT_SPARK_CREATE:    // (cap)
        case EVENT_SPARK_DUD:       // (cap)
        case EVENT_SPARK_OVERFLOW:  // (cap)
        case EVENT_SPARK_RUN:       // (cap)
        case EVENT_SPARK_FIZZLE:    // (cap)
        case EVENT_SPARK_GC:        // (cap)
357
            eventTypes[t].size = 0;
Simon Marlow's avatar
Simon Marlow committed
358
            break;
359 360

        case EVENT_LOG_MSG:          // (msg)
361
        case EVENT_USER_MSG:         // (msg)
362
        case EVENT_USER_MARKER:      // (markername)
363 364 365
        case EVENT_RTS_IDENTIFIER:   // (capset, str)
        case EVENT_PROGRAM_ARGS:     // (capset, strvec)
        case EVENT_PROGRAM_ENV:      // (capset, strvec)
366
        case EVENT_THREAD_LABEL:     // (thread, str)
367 368 369
            eventTypes[t].size = 0xffff;
            break;

Duncan Coutts's avatar
Duncan Coutts committed
370 371 372 373
        case EVENT_SPARK_COUNTERS:   // (cap, 7*counter)
            eventTypes[t].size = 7 * sizeof(StgWord64);
            break;

374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390
        case EVENT_HEAP_ALLOCATED:    // (heap_capset, alloc_bytes)
        case EVENT_HEAP_SIZE:         // (heap_capset, size_bytes)
        case EVENT_HEAP_LIVE:         // (heap_capset, live_bytes)
            eventTypes[t].size = sizeof(EventCapsetID) + sizeof(StgWord64);
            break;

        case EVENT_HEAP_INFO_GHC:     // (heap_capset, n_generations,
                                      //  max_heap_size, alloc_area_size,
                                      //  mblock_size, block_size)
            eventTypes[t].size = sizeof(EventCapsetID)
                               + sizeof(StgWord16)
                               + sizeof(StgWord64) * 4;
            break;

        case EVENT_GC_STATS_GHC:      // (heap_capset, generation,
                                      //  copied_bytes, slop_bytes, frag_bytes,
                                      //  par_n_threads,
391 392 393
                                      //  par_max_copied, par_tot_copied,
                                      //  par_balanced_copied
                                      //  )
394 395 396 397
            eventTypes[t].size = sizeof(EventCapsetID)
                               + sizeof(StgWord16)
                               + sizeof(StgWord64) * 3
                               + sizeof(StgWord32)
398
                               + sizeof(StgWord64) * 3;
399 400
            break;

401
        case EVENT_TASK_CREATE:   // (taskId, cap, tid)
402 403 404
            eventTypes[t].size = sizeof(EventTaskId)
                               + sizeof(EventCapNo)
                               + sizeof(EventKernelThreadId);
405 406 407 408 409 410 411 412 413 414 415
            break;

        case EVENT_TASK_MIGRATE:   // (taskId, cap, new_cap)
            eventTypes[t].size =
                sizeof(EventTaskId) + sizeof(EventCapNo) + sizeof(EventCapNo);
            break;

        case EVENT_TASK_DELETE:   // (taskId)
            eventTypes[t].size = sizeof(EventTaskId);
            break;

Simon Marlow's avatar
Simon Marlow committed
416
        case EVENT_BLOCK_MARKER:
417
            eventTypes[t].size = sizeof(StgWord32) + sizeof(EventTimestamp) +
418
                sizeof(EventCapNo);
Simon Marlow's avatar
Simon Marlow committed
419 420
            break;

421 422 423 424
        case EVENT_HACK_BUG_T9003:
            eventTypes[t].size = 0;
            break;

425 426 427 428 429 430 431 432 433 434 435 436
        case EVENT_HEAP_PROF_BEGIN:
            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
            break;

        case EVENT_HEAP_PROF_COST_CENTRE:
            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
            break;

        case EVENT_HEAP_PROF_SAMPLE_BEGIN:
            eventTypes[t].size = 8;
            break;

437 438 439 440
        case EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN:
            eventTypes[t].size = 16;
            break;

441 442 443 444
        case EVENT_HEAP_PROF_SAMPLE_END:
            eventTypes[t].size = 8;
            break;

445 446 447 448 449 450 451 452
        case EVENT_HEAP_PROF_SAMPLE_STRING:
            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
            break;

        case EVENT_HEAP_PROF_SAMPLE_COST_CENTRE:
            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
            break;

453 454 455 456
        case EVENT_USER_BINARY_MSG:
            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
            break;

457 458 459 460 461 462 463 464 465 466 467 468 469 470 471 472 473
        case EVENT_CONC_MARK_BEGIN:
        case EVENT_CONC_SYNC_BEGIN:
        case EVENT_CONC_SYNC_END:
        case EVENT_CONC_SWEEP_BEGIN:
        case EVENT_CONC_SWEEP_END:
            eventTypes[t].size = 0;
            break;

        case EVENT_CONC_MARK_END:
            eventTypes[t].size = 4;
            break;

        case EVENT_CONC_UPD_REM_SET_FLUSH: // (cap)
            eventTypes[t].size =
                sizeof(EventCapNo);
            break;

474 475 476 477
        case EVENT_NONMOVING_HEAP_CENSUS: // (cap, blk_size, active_segs, filled_segs, live_blks)
            eventTypes[t].size = 13;
            break;

478 479
        default:
            continue; /* ignore deprecated events */
Simon Marlow's avatar
Simon Marlow committed
480
        }
481 482 483 484 485 486 487 488
    }
}

static void
postHeaderEvents(void)
{
    // Write in buffer: the header begin marker.
    postInt32(&eventBuf, EVENT_HEADER_BEGIN);
Simon Marlow's avatar
Simon Marlow committed
489

490 491 492 493
    // Mark beginning of event types in the header.
    postInt32(&eventBuf, EVENT_HET_BEGIN);

    for (int t = 0; t < NUM_GHC_EVENT_TAGS; ++t) {
Simon Marlow's avatar
Simon Marlow committed
494
        // Write in buffer: the start event type.
495 496
        if (eventTypes[t].desc)
            postEventType(&eventBuf, &eventTypes[t]);
Simon Marlow's avatar
Simon Marlow committed
497 498 499
    }

    // Mark end of event types in the header.
Simon Marlow's avatar
Simon Marlow committed
500
    postInt32(&eventBuf, EVENT_HET_END);
501

Simon Marlow's avatar
Simon Marlow committed
502
    // Write in buffer: the header end marker.
Simon Marlow's avatar
Simon Marlow committed
503
    postInt32(&eventBuf, EVENT_HEADER_END);
504

Simon Marlow's avatar
Simon Marlow committed
505
    // Prepare event buffer for events (data).
Simon Marlow's avatar
Simon Marlow committed
506
    postInt32(&eventBuf, EVENT_DATA_BEGIN);
507 508 509 510 511 512 513
}

void
initEventLogging(const EventLogWriter *ev_writer)
{
    uint32_t n_caps;

514 515
    init_event_types();

516 517 518
    event_log_writer = ev_writer;
    initEventLogWriter();

519 520 521 522
    int num_descs = sizeof(EventDesc) / sizeof(char*);
    if (num_descs != NUM_GHC_EVENT_TAGS) {
        barf("EventDesc array has the wrong number of elements (%d, NUM_GHC_EVENT_TAGS=%d)",
             num_descs, NUM_GHC_EVENT_TAGS);
523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544 545 546 547 548
    }

    /*
     * Allocate buffer(s) to store events.
     * Create buffer large enough for the header begin marker, all event
     * types, and header end marker to prevent checking if buffer has room
     * for each of these steps, and remove the need to flush the buffer to
     * disk during initialization.
     *
     * Use a single buffer to store the header with event types, then flush
     * the buffer so all buffers are empty for writing events.
     */
#if defined(THREADED_RTS)
    // XXX n_capabilities hasn't been initialized yet
    n_caps = RtsFlags.ParFlags.nCapabilities;
#else
    n_caps = 1;
#endif
    moreCapEventBufs(0, n_caps);

    initEventsBuf(&eventBuf, EVENT_LOG_SIZE, (EventCapNo)(-1));
#if defined(THREADED_RTS)
    initMutex(&eventBufMutex);
#endif

    postHeaderEvents();
549

550
    // Flush capEventBuf with header.
Simon Marlow's avatar
Simon Marlow committed
551 552 553 554
    /*
     * Flush header and data begin marker to the file, thus preparing the
     * file to have events written to it.
     */
555
    printAndClearEventBuf(&eventBuf);
Simon Marlow's avatar
Simon Marlow committed
556

557
    for (uint32_t c = 0; c < n_caps; ++c) {
Simon Marlow's avatar
Simon Marlow committed
558 559
        postBlockMarker(&capEventBuf[c]);
    }
Simon Marlow's avatar
Simon Marlow committed
560 561 562 563 564 565
}

void
endEventLogging(void)
{
    // Flush all events remaining in the buffers.
566
    for (uint32_t c = 0; c < n_capabilities; ++c) {
567
        printAndClearEventBuf(&capEventBuf[c]);
Simon Marlow's avatar
Simon Marlow committed
568
    }
569
    printAndClearEventBuf(&eventBuf);
570
    resetEventsBuf(&eventBuf); // we don't want the block marker
Simon Marlow's avatar
Simon Marlow committed
571 572

    // Mark end of events (data).
Simon Marlow's avatar
Simon Marlow committed
573
    postEventTypeNum(&eventBuf, EVENT_DATA_END);
Simon Marlow's avatar
Simon Marlow committed
574 575

    // Flush the end of data marker.
576
    printAndClearEventBuf(&eventBuf);
Simon Marlow's avatar
Simon Marlow committed
577

578
    stopEventLogWriter();
Simon Marlow's avatar
Simon Marlow committed
579 580
}

581
void
582
moreCapEventBufs (uint32_t from, uint32_t to)
583 584 585 586 587 588 589 590 591
{
    if (from > 0) {
        capEventBuf = stgReallocBytes(capEventBuf, to * sizeof(EventsBuf),
                                      "moreCapEventBufs");
    } else {
        capEventBuf = stgMallocBytes(to * sizeof(EventsBuf),
                                     "moreCapEventBufs");
    }

592
    for (uint32_t c = from; c < to; ++c) {
593 594
        initEventsBuf(&capEventBuf[c], EVENT_LOG_SIZE, c);
    }
595 596 597 598

    // The from == 0 already covered in initEventLogging, so we are interested
    // only in case when we are increasing capabilities number
    if (from > 0) {
599
        for (uint32_t c = from; c < to; ++c) {
600 601 602
           postBlockMarker(&capEventBuf[c]);
        }
    }
603 604 605 606
}


void
Simon Marlow's avatar
Simon Marlow committed
607 608 609
freeEventLogging(void)
{
    // Free events buffer.
610
    for (uint32_t c = 0; c < n_capabilities; ++c) {
611
        if (capEventBuf[c].begin != NULL)
612
            stgFree(capEventBuf[c].begin);
Simon Marlow's avatar
Simon Marlow committed
613
    }
614 615
    if (capEventBuf != NULL)  {
        stgFree(capEventBuf);
Simon Marlow's avatar
Simon Marlow committed
616
    }
617 618
}

619
void
620 621 622
abortEventLogging(void)
{
    freeEventLogging();
623
    stopEventLogWriter();
624
}
625

Simon Marlow's avatar
Simon Marlow committed
626 627 628 629 630
/*
 * Post an event message to the capability's eventlog buffer.
 * If the buffer is full, prints out the buffer and clears it.
 */
void
631 632 633
postSchedEvent (Capability *cap,
                EventTypeNum tag,
                StgThreadID thread,
634 635
                StgWord info1,
                StgWord info2)
Simon Marlow's avatar
Simon Marlow committed
636
{
637
    EventsBuf *eb = &capEventBuf[cap->no];
638
    ensureRoomForEvent(eb, tag);
639

Simon Marlow's avatar
Simon Marlow committed
640
    postEventHeader(eb, tag);
Simon Marlow's avatar
Simon Marlow committed
641 642 643 644 645 646

    switch (tag) {
    case EVENT_CREATE_THREAD:   // (cap, thread)
    case EVENT_RUN_THREAD:      // (cap, thread)
    case EVENT_THREAD_RUNNABLE: // (cap, thread)
    {
647
        postThreadID(eb,thread);
Simon Marlow's avatar
Simon Marlow committed
648 649 650
        break;
    }

651
    case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
652
    {
653
        postThreadID(eb,info1 /* spark_thread */);
654 655 656
        break;
    }

Simon Marlow's avatar
Simon Marlow committed
657 658 659
    case EVENT_MIGRATE_THREAD:  // (cap, thread, new_cap)
    case EVENT_THREAD_WAKEUP:   // (cap, thread, other_cap)
    {
660
        postThreadID(eb,thread);
661
        postCapNo(eb,info1 /* new_cap | victim_cap | other_cap */);
Simon Marlow's avatar
Simon Marlow committed
662
        break;
663
   }
Simon Marlow's avatar
Simon Marlow committed
664 665 666

    case EVENT_STOP_THREAD:     // (cap, thread, status)
    {
667
        postThreadID(eb,thread);
668 669
        postWord16(eb,info1 /* status */);
        postThreadID(eb,info2 /* blocked on thread */);
Simon Marlow's avatar
Simon Marlow committed
670 671 672 673
        break;
    }

    default:
674
        barf("postSchedEvent: unknown event tag %d", tag);
Simon Marlow's avatar
Simon Marlow committed
675
    }
676 677
}

678 679 680 681 682
void
postSparkEvent (Capability *cap,
                EventTypeNum tag,
                StgWord info1)
{
683
    EventsBuf *eb = &capEventBuf[cap->no];
684
    ensureRoomForEvent(eb, tag);
685 686 687 688 689 690 691 692 693 694 695 696 697 698 699 700 701 702 703 704 705 706 707 708 709 710 711 712 713 714 715

    postEventHeader(eb, tag);

    switch (tag) {
    case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
    {
        postThreadID(eb,info1 /* spark_thread */);
        break;
    }

    case EVENT_SPARK_STEAL:         // (cap, victim_cap)
    {
        postCapNo(eb,info1 /* victim_cap */);
        break;
   }

    case EVENT_SPARK_CREATE:        // (cap)
    case EVENT_SPARK_DUD:           // (cap)
    case EVENT_SPARK_OVERFLOW:      // (cap)
    case EVENT_SPARK_RUN:           // (cap)
    case EVENT_SPARK_FIZZLE:        // (cap)
    case EVENT_SPARK_GC:            // (cap)
    {
        break;
    }

    default:
        barf("postSparkEvent: unknown event tag %d", tag);
    }
}

Duncan Coutts's avatar
Duncan Coutts committed
716
void
717
postSparkCountersEvent (Capability *cap,
Duncan Coutts's avatar
Duncan Coutts committed
718 719 720
                        SparkCounters counters,
                        StgWord remaining)
{
721
    EventsBuf *eb = &capEventBuf[cap->no];
722
    ensureRoomForEvent(eb, EVENT_SPARK_COUNTERS);
723

Duncan Coutts's avatar
Duncan Coutts committed
724
    postEventHeader(eb, EVENT_SPARK_COUNTERS);
725
    /* EVENT_SPARK_COUNTERS (crt,dud,ovf,cnv,gcd,fiz,rem) */
Duncan Coutts's avatar
Duncan Coutts committed
726 727 728 729 730 731 732 733 734
    postWord64(eb,counters.created);
    postWord64(eb,counters.dud);
    postWord64(eb,counters.overflowed);
    postWord64(eb,counters.converted);
    postWord64(eb,counters.gcd);
    postWord64(eb,counters.fizzled);
    postWord64(eb,remaining);
}

735 736 737 738 739
void
postCapEvent (EventTypeNum  tag,
              EventCapNo    capno)
{
    ACQUIRE_LOCK(&eventBufMutex);
740
    ensureRoomForEvent(&eventBuf, tag);
741

742 743 744 745 746 747 748 749 750 751 752 753 754 755 756 757 758 759 760
    postEventHeader(&eventBuf, tag);

    switch (tag) {
    case EVENT_CAP_CREATE:   // (cap)
    case EVENT_CAP_DELETE:   // (cap)
    case EVENT_CAP_ENABLE:   // (cap)
    case EVENT_CAP_DISABLE:  // (cap)
    {
        postCapNo(&eventBuf,capno);
        break;
    }

    default:
        barf("postCapEvent: unknown event tag %d", tag);
    }

    RELEASE_LOCK(&eventBufMutex);
}

761 762 763
void postCapsetEvent (EventTypeNum tag,
                      EventCapsetID capset,
                      StgWord info)
764 765
{
    ACQUIRE_LOCK(&eventBufMutex);
766
    ensureRoomForEvent(&eventBuf, tag);
767 768 769 770 771 772 773

    postEventHeader(&eventBuf, tag);
    postCapsetID(&eventBuf, capset);

    switch (tag) {
    case EVENT_CAPSET_CREATE:   // (capset, capset_type)
    {
774
        postCapsetType(&eventBuf, info /* capset_type */);
775 776 777 778 779 780 781 782 783 784 785
        break;
    }

    case EVENT_CAPSET_DELETE:   // (capset)
    {
        break;
    }

    case EVENT_CAPSET_ASSIGN_CAP:  // (capset, capno)
    case EVENT_CAPSET_REMOVE_CAP:  // (capset, capno)
    {
786
        postCapNo(&eventBuf, info /* capno */);
787 788
        break;
    }
789 790 791
    case EVENT_OSPROCESS_PID:   // (capset, pid)
    case EVENT_OSPROCESS_PPID:  // (capset, parent_pid)
    {
792
        postOSProcessId(&eventBuf, info);
793 794
        break;
    }
795
    default:
796
        barf("postCapsetEvent: unknown event tag %d", tag);
797 798 799 800 801
    }

    RELEASE_LOCK(&eventBufMutex);
}

802 803 804 805 806
void postCapsetStrEvent (EventTypeNum tag,
                         EventCapsetID capset,
                         char *msg)
{
    int strsize = strlen(msg);
807
    int size = strsize + sizeof(EventCapsetID);
808 809 810 811
    if (size > EVENT_PAYLOAD_SIZE_MAX) {
        errorBelch("Event size exceeds EVENT_PAYLOAD_SIZE_MAX, bail out");
        return;
    }
812 813 814 815 816 817 818

    ACQUIRE_LOCK(&eventBufMutex);

    if (!hasRoomForVariableEvent(&eventBuf, size)){
        printAndClearEventBuf(&eventBuf);

        if (!hasRoomForVariableEvent(&eventBuf, size)){
819
            errorBelch("Event size exceeds buffer size, bail out");
820 821 822 823 824 825 826 827 828 829 830 831 832 833 834 835 836 837 838
            RELEASE_LOCK(&eventBufMutex);
            return;
        }
    }

    postEventHeader(&eventBuf, tag);
    postPayloadSize(&eventBuf, size);
    postCapsetID(&eventBuf, capset);

    postBuf(&eventBuf, (StgWord8*) msg, strsize);

    RELEASE_LOCK(&eventBufMutex);
}

void postCapsetVecEvent (EventTypeNum tag,
                         EventCapsetID capset,
                         int argc,
                         char *argv[])
{
839
    int size = sizeof(EventCapsetID);
840

841
    for (int i = 0; i < argc; i++) {
842 843 844 845 846 847 848 849 850 851
        // 1 + strlen to account for the trailing \0, used as separator
        size += 1 + strlen(argv[i]);
    }

    ACQUIRE_LOCK(&eventBufMutex);

    if (!hasRoomForVariableEvent(&eventBuf, size)){
        printAndClearEventBuf(&eventBuf);

        if(!hasRoomForVariableEvent(&eventBuf, size)){
852
            errorBelch("Event size exceeds buffer size, bail out");
853 854 855 856 857 858 859 860 861
            RELEASE_LOCK(&eventBufMutex);
            return;
        }
    }

    postEventHeader(&eventBuf, tag);
    postPayloadSize(&eventBuf, size);
    postCapsetID(&eventBuf, capset);

862
    for (int i = 0; i < argc; i++) {
863 864 865 866 867 868 869
        // again, 1 + to account for \0
        postBuf(&eventBuf, (StgWord8*) argv[i], 1 + strlen(argv[i]));
    }

    RELEASE_LOCK(&eventBufMutex);
}

870 871 872 873 874 875 876
void postWallClockTime (EventCapsetID capset)
{
    StgWord64 ts;
    StgWord64 sec;
    StgWord32 nsec;

    ACQUIRE_LOCK(&eventBufMutex);
877

878 879 880 881 882 883 884 885 886 887 888 889 890 891 892
    /* The EVENT_WALL_CLOCK_TIME event is intended to allow programs
       reading the eventlog to match up the event timestamps with wall
       clock time. The normal event timestamps measure time since the
       start of the program. To align eventlogs from concurrent
       processes we need to be able to match up the timestamps. One way
       to do this is if we know how the timestamps and wall clock time
       match up (and of course if both processes have sufficiently
       synchronised clocks).

       So we want to make sure that the timestamp that we generate for
       this event matches up very closely with the wall clock time.
       Unfortunately we currently have to use two different APIs to get
       the elapsed time vs the wall clock time. So to minimise the
       difference we just call them very close together.
     */
893

894 895
    getUnixEpochTime(&sec, &nsec);  /* Get the wall clock time */
    ts = time_ns();                 /* Get the eventlog timestamp */
896
    ensureRoomForEvent(&eventBuf, EVENT_WALL_CLOCK_TIME);
897 898 899 900 901 902

    /* Normally we'd call postEventHeader(), but that generates its own
       timestamp, so we go one level lower so we can write out the
       timestamp we already generated above. */
    postEventTypeNum(&eventBuf, EVENT_WALL_CLOCK_TIME);
    postWord64(&eventBuf, ts);
903

904 905 906 907 908 909 910 911
    /* EVENT_WALL_CLOCK_TIME (capset, unix_epoch_seconds, nanoseconds) */
    postCapsetID(&eventBuf, capset);
    postWord64(&eventBuf, sec);
    postWord32(&eventBuf, nsec);

    RELEASE_LOCK(&eventBufMutex);
}

912 913 914 915 916 917
/*
 * Various GC and heap events
 */
void postHeapEvent (Capability    *cap,
                    EventTypeNum   tag,
                    EventCapsetID  heap_capset,
918
                    W_           info1)
919
{
920
    EventsBuf *eb = &capEventBuf[cap->no];
921
    ensureRoomForEvent(eb, tag);
922

923 924 925 926 927 928 929 930
    postEventHeader(eb, tag);

    switch (tag) {
    case EVENT_HEAP_ALLOCATED:     // (heap_capset, alloc_bytes)
    case EVENT_HEAP_SIZE:          // (heap_capset, size_bytes)
    case EVENT_HEAP_LIVE:          // (heap_capset, live_bytes)
    {
        postCapsetID(eb, heap_capset);
931
        postWord64(eb, info1 /* alloc/size/live_bytes */);
932 933 934 935 936 937 938 939 940
        break;
    }

    default:
        barf("postHeapEvent: unknown event tag %d", tag);
    }
}

void postEventHeapInfo (EventCapsetID heap_capset,
941
                        uint32_t    gens,
942 943 944 945
                        W_          maxHeapSize,
                        W_          allocAreaSize,
                        W_          mblockSize,
                        W_          blockSize)
946 947
{
    ACQUIRE_LOCK(&eventBufMutex);
948
    ensureRoomForEvent(&eventBuf, EVENT_HEAP_INFO_GHC);
949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 964 965

    postEventHeader(&eventBuf, EVENT_HEAP_INFO_GHC);
    /* EVENT_HEAP_INFO_GHC (heap_capset, n_generations,
                            max_heap_size, alloc_area_size,
                            mblock_size, block_size) */
    postCapsetID(&eventBuf, heap_capset);
    postWord16(&eventBuf, gens);
    postWord64(&eventBuf, maxHeapSize);
    postWord64(&eventBuf, allocAreaSize);
    postWord64(&eventBuf, mblockSize);
    postWord64(&eventBuf, blockSize);

    RELEASE_LOCK(&eventBufMutex);
}

void postEventGcStats  (Capability    *cap,
                        EventCapsetID  heap_capset,
966
                        uint32_t     gen,
967 968 969
                        W_           copied,
                        W_           slop,
                        W_           fragmentation,
970
                        uint32_t     par_n_threads,
971
                        W_           par_max_copied,
972 973
                        W_           par_tot_copied,
                        W_           par_balanced_copied)
974
{
975
    EventsBuf *eb = &capEventBuf[cap->no];
976
    ensureRoomForEvent(eb, EVENT_GC_STATS_GHC);
977

978 979 980
    postEventHeader(eb, EVENT_GC_STATS_GHC);
    /* EVENT_GC_STATS_GHC (heap_capset, generation,
                           copied_bytes, slop_bytes, frag_bytes,
981 982
                           par_n_threads, par_max_copied,
                           par_tot_copied, par_balanced_copied) */
983 984 985 986 987 988 989 990
    postCapsetID(eb, heap_capset);
    postWord16(eb, gen);
    postWord64(eb, copied);
    postWord64(eb, slop);
    postWord64(eb, fragmentation);
    postWord32(eb, par_n_threads);
    postWord64(eb, par_max_copied);
    postWord64(eb, par_tot_copied);
991
    postWord64(eb, par_balanced_copied);
992 993
}

994 995 996 997 998
void postTaskCreateEvent (EventTaskId taskId,
                          EventCapNo capno,
                          EventKernelThreadId tid)
{
    ACQUIRE_LOCK(&eventBufMutex);
999
    ensureRoomForEvent(&eventBuf, EVENT_TASK_CREATE);
1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014

    postEventHeader(&eventBuf, EVENT_TASK_CREATE);
    /* EVENT_TASK_CREATE (taskID, cap, tid) */
    postTaskId(&eventBuf, taskId);
    postCapNo(&eventBuf, capno);
    postKernelThreadId(&eventBuf, tid);

    RELEASE_LOCK(&eventBufMutex);
}

void postTaskMigrateEvent (EventTaskId taskId,
                           EventCapNo capno,
                           EventCapNo new_capno)
{
    ACQUIRE_LOCK(&eventBufMutex);
1015
    ensureRoomForEvent(&eventBuf, EVENT_TASK_MIGRATE);
1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028

    postEventHeader(&eventBuf, EVENT_TASK_MIGRATE);
    /* EVENT_TASK_MIGRATE (taskID, cap, new_cap) */
    postTaskId(&eventBuf, taskId);
    postCapNo(&eventBuf, capno);
    postCapNo(&eventBuf, new_capno);

    RELEASE_LOCK(&eventBufMutex);
}

void postTaskDeleteEvent (EventTaskId taskId)
{
    ACQUIRE_LOCK(&eventBufMutex);
1029
    ensureRoomForEvent(&eventBuf, EVENT_TASK_DELETE);
1030 1031 1032 1033 1034 1035 1036 1037

    postEventHeader(&eventBuf, EVENT_TASK_DELETE);
    /* EVENT_TASK_DELETE (taskID) */
    postTaskId(&eventBuf, taskId);

    RELEASE_LOCK(&eventBufMutex);
}

1038 1039 1040 1041 1042 1043 1044 1045 1046
void
postEventNoCap (EventTypeNum tag)
{
    ACQUIRE_LOCK(&eventBufMutex);
    ensureRoomForEvent(&eventBuf, tag);
    postEventHeader(&eventBuf, tag);
    RELEASE_LOCK(&eventBufMutex);
}

1047 1048 1049
void
postEvent (Capability *cap, EventTypeNum tag)
{
1050
    EventsBuf *eb = &capEventBuf[cap->no];
1051
    ensureRoomForEvent(eb, tag);
1052 1053 1054
    postEventHeader(eb, tag);
}

1055 1056 1057
void
postEventAtTimestamp (Capability *cap, EventTimestamp ts, EventTypeNum tag)
{
1058
    EventsBuf *eb = &capEventBuf[cap->no];
1059
    ensureRoomForEvent(eb, tag);
1060 1061 1062 1063 1064 1065 1066 1067

    /* Normally we'd call postEventHeader(), but that generates its own
       timestamp, so we go one level lower so we can write out
       the timestamp we received as an argument. */
    postEventTypeNum(eb, tag);
    postWord64(eb, ts);
}

1068 1069
#define BUF 512

1070
void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap)
1071 1072
{
    char buf[BUF];
1073
    uint32_t size = vsnprintf(buf, BUF, msg,ap);
1074 1075 1076 1077 1078
    if (size > BUF) {
        buf[BUF-1] = '\0';
        size = BUF;
    }

1079
    ensureRoomForVariableEvent(eb, size);
1080

1081
    postEventHeader(eb, type);
1082 1083
    postPayloadSize(eb, size);
    postBuf(eb,(StgWord8*)buf,size);
1084
}
1085

1086 1087 1088
void postMsg(char *msg, va_list ap)
{
    ACQUIRE_LOCK(&eventBufMutex);
1089
    postLogMsg(&eventBuf, EVENT_LOG_MSG, msg, ap);
1090 1091 1092 1093 1094
    RELEASE_LOCK(&eventBufMutex);
}

void postCapMsg(Capability *cap, char *msg, va_list ap)
{
1095
    postLogMsg(&capEventBuf[cap->no], EVENT_LOG_MSG, msg, ap);
Simon Marlow's avatar
Simon Marlow committed
1096 1097
}

1098
void postUserEvent(Capability *cap, EventTypeNum type, char *msg)
1099
{
1100 1101 1102 1103 1104 1105
    const size_t size = strlen(msg);
    if (size > EVENT_PAYLOAD_SIZE_MAX) {
        errorBelch("Event size exceeds EVENT_PAYLOAD_SIZE_MAX, bail out");
        return;
    }

1106
    EventsBuf *eb = &capEventBuf[cap->no];
1107 1108 1109 1110 1111 1112 1113 1114
    if (!hasRoomForVariableEvent(eb, size)){
        printAndClearEventBuf(eb);

        if (!hasRoomForVariableEvent(eb, size)){
            errorBelch("Event size exceeds buffer size, bail out");
            return;
        }
    }
1115

1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131
    postEventHeader(eb, type);
    postPayloadSize(eb, size);
    postBuf(eb, (StgWord8*) msg, size);
}

void postUserBinaryEvent(Capability   *cap,
                         EventTypeNum  type,
                         uint8_t      *msg,
                         size_t        size)
{
    if (size > EVENT_PAYLOAD_SIZE_MAX) {
        errorBelch("Event size exceeds EVENT_PAYLOAD_SIZE_MAX, bail out");
        return;
    }

    EventsBuf *eb = &capEventBuf[cap->no];
1132 1133 1134 1135
    if (!hasRoomForVariableEvent(eb, size)){
        printAndClearEventBuf(eb);

        if (!hasRoomForVariableEvent(eb, size)){
1136
            errorBelch("Event size exceeds buffer size, bail out");
1137 1138 1139 1140
            return;
        }
    }

1141
    postEventHeader(eb, type);
1142
    postPayloadSize(eb, size);
1143
    postBuf(eb, (StgWord8*) msg, size);
1144 1145
}

1146 1147 1148 1149
void postThreadLabel(Capability    *cap,
                     EventThreadID  id,
                     char          *label)
{
1150 1151
    const int strsize = strlen(label);
    const int size = strsize + sizeof(EventThreadID);
1152 1153 1154 1155
    if (size > EVENT_PAYLOAD_SIZE_MAX) {
        errorBelch("Event size exceeds EVENT_PAYLOAD_SIZE_MAX, bail out");
        return;
    }
1156

1157
    EventsBuf *eb = &capEventBuf[cap->no];
1158 1159 1160 1161
    if (!hasRoomForVariableEvent(eb, size)){
        printAndClearEventBuf(eb);

        if (!hasRoomForVariableEvent(eb, size)){
1162
            errorBelch("Event size exceeds buffer size, bail out");
1163 1164 1165 1166 1167 1168 1169 1170 1171 1172
            return;
        }
    }

    postEventHeader(eb, EVENT_THREAD_LABEL);
    postPayloadSize(eb, size);
    postThreadID(eb, id);
    postBuf(eb, (StgWord8*) label, strsize);
}

1173 1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184 1185 1186 1187 1188 1189
void postConcUpdRemSetFlush(Capability *cap)
{
    EventsBuf *eb = &capEventBuf[cap->no];
    ensureRoomForEvent(eb, EVENT_CONC_UPD_REM_SET_FLUSH);
    postEventHeader(eb, EVENT_CONC_UPD_REM_SET_FLUSH);
    postCapNo(eb, cap->no);
}

void postConcMarkEnd(StgWord32 marked_obj_count)
{
    ACQUIRE_LOCK(&eventBufMutex);
    ensureRoomForEvent(&eventBuf, EVENT_CONC_MARK_END);
    postEventHeader(&eventBuf, EVENT_CONC_MARK_END);
    postWord32(&eventBuf, marked_obj_count);
    RELEASE_LOCK(&eventBufMutex);
}

1190 1191 1192 1193 1194 1195 1196 1197 1198 1199 1200 1201
void postNonmovingHeapCensus(int log_blk_size,
                             const struct NonmovingAllocCensus *census)
{
    ACQUIRE_LOCK(&eventBufMutex);
    postEventHeader(&eventBuf, EVENT_NONMOVING_HEAP_CENSUS);
    postWord8(&eventBuf, log_blk_size);
    postWord32(&eventBuf, census->n_active_segs);
    postWord32(&eventBuf, census->n_filled_segs);
    postWord32(&eventBuf, census->n_live_blocks);
    RELEASE_LOCK(&eventBufMutex);
}

Simon Marlow's avatar
Simon Marlow committed
1202 1203 1204 1205 1206
void closeBlockMarker (EventsBuf *ebuf)
{
    if (ebuf->marker)
    {
        // (type:16, time:64, size:32, end_time:64)
1207

1208
        StgInt8* save_pos = ebuf->pos;
1209 1210 1211 1212 1213
        ebuf->pos = ebuf->marker + sizeof(EventTypeNum) +
                    sizeof(EventTimestamp);
        postWord32(ebuf, save_pos - ebuf->marker);
        postTimestamp(ebuf);
        ebuf->pos = save_pos;
Simon Marlow's avatar
Simon Marlow committed
1214 1215 1216 1217 1218 1219 1220
        ebuf->marker = NULL;
    }
}


void postBlockMarker (EventsBuf *eb)
{
1221
    ensureRoomForEvent(eb, EVENT_BLOCK_MARKER);
Simon Marlow's avatar
Simon Marlow committed
1222 1223 1224 1225 1226 1227 1228

    closeBlockMarker(eb);

    eb->marker = eb->pos;
    postEventHeader(eb, EVENT_BLOCK_MARKER);
    postWord32(eb,0); // these get filled in later by closeBlockMarker();
    postWord64(eb,0);
1229
    postCapNo(eb, eb->capno);
Simon Marlow's avatar
Simon Marlow committed
1230 1231
}

1232 1233 1234 1235 1236 1237 1238 1239 1240 1241 1242 1243 1244 1245 1246
static HeapProfBreakdown getHeapProfBreakdown(void)
{
    switch (RtsFlags.ProfFlags.doHeapProfile) {
    case HEAP_BY_CCS:
        return HEAP_PROF_BREAKDOWN_COST_CENTRE;
    case HEAP_BY_MOD:
        return HEAP_PROF_BREAKDOWN_MODULE;
    case HEAP_BY_DESCR:
        return HEAP_PROF_BREAKDOWN_CLOSURE_DESCR;
    case HEAP_BY_TYPE:
        return HEAP_PROF_BREAKDOWN_TYPE_DESCR;
    case HEAP_BY_RETAINER:
        return HEAP_PROF_BREAKDOWN_RETAINER;
    case HEAP_BY_LDV:
        return HEAP_PROF_BREAKDOWN_BIOGRAPHY;
1247 1248
    case HEAP_BY_CLOSURE_TYPE:
        return HEAP_PROF_BREAKDOWN_CLOSURE_TYPE;
1249 1250 1251 1252 1253 1254 1255 1256 1257 1258 1259 1260 1261 1262 1263 1264 1265 1266 1267 1268 1269 1270 1271 1272 1273 1274 1275 1276 1277 1278 1279 1280 1281 1282 1283 1284 1285 1286 1287 1288 1289 1290 1291 1292 1293 1294 1295 1296 1297 1298 1299 1300
    default:
        barf("getHeapProfBreakdown: unknown heap profiling mode");
    }
}

void postHeapProfBegin(StgWord8 profile_id)
{
    ACQUIRE_LOCK(&eventBufMutex);
    PROFILING_FLAGS *flags = &RtsFlags.ProfFlags;
    StgWord modSelector_len   =
        flags->modSelector ? strlen(flags->modSelector) : 0;
    StgWord descrSelector_len =
        flags->descrSelector ? strlen(flags->descrSelector) : 0;
    StgWord typeSelector_len  =
        flags->typeSelector ? strlen(flags->typeSelector) : 0;
    StgWord ccSelector_len    =
        flags->ccSelector ? strlen(flags->ccSelector) : 0;
    StgWord ccsSelector_len   =
        flags->ccsSelector ? strlen(flags->ccsSelector) : 0;
    StgWord retainerSelector_len =
        flags->retainerSelector ? strlen(flags->retainerSelector) : 0;
    StgWord bioSelector_len   =
        flags->bioSelector ? strlen(flags->bioSelector) : 0;
    StgWord len =
        1+8+4 + modSelector_len + descrSelector_len +
        typeSelector_len + ccSelector_len + ccsSelector_len +
        retainerSelector_len + bioSelector_len + 7;
    ensureRoomForVariableEvent(&eventBuf, len);
    postEventHeader(&eventBuf, EVENT_HEAP_PROF_BEGIN);
    postPayloadSize(&eventBuf, len);
    postWord8(&eventBuf, profile_id);
    postWord64(&eventBuf, TimeToNS(flags->heapProfileInterval));
    postWord32(&eventBuf, getHeapProfBreakdown());
    postString(&eventBuf, flags->modSelector);
    postString(&eventBuf, flags->descrSelector);
    postString(&eventBuf, flags->typeSelector);
    postString(&eventBuf, flags->ccSelector);
    postString(&eventBuf, flags->ccsSelector);
    postString(&eventBuf, flags->retainerSelector);
    postString(&eventBuf, flags->bioSelector);
    RELEASE_LOCK(&eventBufMutex);
}

void postHeapProfSampleBegin(StgInt era)
{
    ACQUIRE_LOCK(&eventBufMutex);
    ensureRoomForEvent(&eventBuf, EVENT_HEAP_PROF_SAMPLE_BEGIN);
    postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_BEGIN);
    postWord64(&eventBuf, era);
    RELEASE_LOCK(&eventBufMutex);
}

1301 1302 1303 1304 1305 1306 1307 1308 1309 1310 1311

void postHeapBioProfSampleBegin(StgInt era, StgWord64 time)
{
    ACQUIRE_LOCK(&eventBufMutex);
    ensureRoomForEvent(&eventBuf, EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN);
    postEventHeader(&eventBuf, EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN);
    postWord64(&eventBuf, era);
    postWord64(&eventBuf, time);
    RELEASE_LOCK(&eventBufMutex);
}

1312 1313 1314 1315 1316 1317 1318 1319 1320
void postHeapProfSampleEnd(StgInt era)
{
    ACQUIRE_LOCK(&eventBufMutex);
    ensureRoomForEvent(&eventBuf, EVENT_HEAP_PROF_SAMPLE_END);
    postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_END);
    postWord64(&eventBuf, era);
    RELEASE_LOCK(&eventBufMutex);
}

1321 1322 1323 1324 1325 1326 1327 1328 1329 1330 1331 1332 1333 1334 1335 1336
void postHeapProfSampleString(StgWord8 profile_id,
                              const char *label,
                              StgWord64 residency)
{
    ACQUIRE_LOCK(&eventBufMutex);
    StgWord label_len = strlen(label);
    StgWord len = 1+8+label_len+1;
    ensureRoomForVariableEvent(&eventBuf, len);
    postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_STRING);
    postPayloadSize(&eventBuf, len);
    postWord8(&eventBuf, profile_id);
    postWord64(&eventBuf, residency);
    postString(&eventBuf, label);
    RELEASE_LOCK(&eventBufMutex);
}

Ben Gamari's avatar
Ben Gamari committed
1337
#if defined(PROFILING)
1338 1339 1340 1341 1342 1343 1344 1345 1346 1347 1348 1349 1350 1351 1352 1353 1354 1355 1356 1357 1358 1359 1360 1361 1362 1363 1364 1365 1366 1367 1368 1369 1370 1371 1372 1373 1374 1375 1376 1377 1378 1379 1380 1381 1382 1383 1384 1385
void postHeapProfCostCentre(StgWord32 ccID,
                            const char *label,
                            const char *module,
                            const char *srcloc,
                            StgBool is_caf)
{
    ACQUIRE_LOCK(&eventBufMutex);
    StgWord label_len = strlen(label);
    StgWord module_len = strlen(module);
    StgWord srcloc_len = strlen(srcloc);
    StgWord len = 4+label_len+module_len+srcloc_len+3+1;
    ensureRoomForVariableEvent(&eventBuf, len);
    postEventHeader(&eventBuf, EVENT_HEAP_PROF_COST_CENTRE);
    postPayloadSize(&eventBuf, len);
    postWord32(&eventBuf, ccID);
    postString(&eventBuf, label);
    postString(&eventBuf, module);
    postString(&eventBuf, srcloc);
    postWord8(&eventBuf, is_caf);
    RELEASE_LOCK(&eventBufMutex);
}

void postHeapProfSampleCostCentre(StgWord8 profile_id,
                                  CostCentreStack *stack,
                                  StgWord64 residency)
{
    ACQUIRE_LOCK(&eventBufMutex);
    StgWord depth = 0;
    CostCentreStack *ccs;
    for (ccs = stack; ccs != NULL && ccs != CCS_MAIN; ccs = ccs->prevStack)
        depth++;
    if (depth > 0xff) depth =