Add capability sets to the tracing/events system
[ghc-hetmet.git] / rts / eventlog / EventLog.c
index 178dfb3..b5c2ef6 100644 (file)
 
 #include "Trace.h"
 #include "Capability.h"
-#include "Trace.h"
 #include "RtsUtils.h"
 #include "Stats.h"
 #include "EventLog.h"
 
-#include <string.h> 
+#include <string.h>
 #include <stdio.h>
+#ifdef HAVE_SYS_TYPES_H
+#include <sys/types.h>
+#endif
+#ifdef HAVE_UNISTD_H
+#include <unistd.h>
+#endif
+
+// PID of the process that writes to event_log_filename (#4512)
+static pid_t event_log_pid = -1;
 
 static char *event_log_filename = NULL;
 
@@ -36,6 +44,7 @@ typedef struct _EventsBuf {
   StgInt8 *pos;
   StgInt8 *marker;
   StgWord64 size;
+  EventCapNo capno; // which capability this buffer belongs to, or -1
 } EventsBuf;
 
 EventsBuf *capEventBuf; // one EventsBuf for each Capability
@@ -60,10 +69,17 @@ char *EventDesc[] = {
   [EVENT_REQUEST_SEQ_GC]      = "Request sequential GC",
   [EVENT_REQUEST_PAR_GC]      = "Request parallel GC",
   [EVENT_CREATE_SPARK_THREAD] = "Create spark thread",
-  [EVENT_LOG_CAP_MSG]         = "Log Capability message",
   [EVENT_LOG_MSG]             = "Log message",
+  [EVENT_USER_MSG]            = "User message",
   [EVENT_STARTUP]             = "Startup",
-  [EVENT_BLOCK_MARKER]        = "Block marker"
+  [EVENT_GC_IDLE]             = "GC idle",
+  [EVENT_GC_WORK]             = "GC working",
+  [EVENT_GC_DONE]             = "GC done",
+  [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",
+  [EVENT_CAPSET_REMOVE_CAP]   = "Remove capability from capability set"
 };
 
 // Event type. 
@@ -76,12 +92,14 @@ typedef struct _EventType {
 
 EventType eventTypes[NUM_EVENT_TAGS];
 
-static void initEventsBuf(EventsBuf* eb, StgWord64 size);
+static void initEventsBuf(EventsBuf* eb, StgWord64 size, EventCapNo capno);
 static void resetEventsBuf(EventsBuf* eb);
 static void printAndClearEventBuf (EventsBuf *eventsBuf);
 
 static void postEventType(EventsBuf *eb, EventType *et);
 
+static void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap);
+
 static void postBlockMarker(EventsBuf *eb);
 static void closeBlockMarker(EventsBuf *ebuf);
 
@@ -132,6 +150,12 @@ static inline void postThreadID(EventsBuf *eb, EventThreadID id)
 static inline void postCapNo(EventsBuf *eb, EventCapNo no)
 { postWord16(eb,no); }
 
+static inline void postCapsetID(EventsBuf *eb, EventCapsetID id)
+{ postWord32(eb,id); }
+
+static inline void postCapsetType(EventsBuf *eb, EventCapsetType type)
+{ postWord16(eb,type); }
+
 static inline void postPayloadSize(EventsBuf *eb, EventPayloadSize size)
 { postWord16(eb,size); }
 
@@ -160,18 +184,29 @@ initEventLogging(void)
     StgWord8 t, c;
     nat n_caps;
 
-    event_log_filename = stgMallocBytes(strlen(prog_name) + 10,
+    event_log_filename = stgMallocBytes(strlen(prog_name)
+                                        + 10 /* .%d */
+                                        + 10 /* .eventlog */,
                                         "initEventLogging");
 
     if (sizeof(EventDesc) / sizeof(char*) != NUM_EVENT_TAGS) {
         barf("EventDesc array has the wrong number of elements");
     }
-  
-    sprintf(event_log_filename, "%s.eventlog", prog_name);
-    
+
+    if (event_log_pid == -1) { // #4512
+        // Single process
+        sprintf(event_log_filename, "%s.eventlog", prog_name);
+        event_log_pid = getpid();
+    } else {
+        // Forked process, eventlog already started by the parent
+        // before fork
+        event_log_pid = getpid();
+        sprintf(event_log_filename, "%s.%d.eventlog", prog_name, event_log_pid);
+    }
+
     /* Open event log file for writing. */
     if ((event_log_file = fopen(event_log_filename, "wb")) == NULL) {
-        sysErrorBelch("initEventLoggin: can't open %s", event_log_filename);
+        sysErrorBelch("initEventLogging: can't open %s", event_log_filename);
         stg_exit(EXIT_FAILURE);    
     }
 
@@ -195,9 +230,9 @@ initEventLogging(void)
 
     for (c = 0; c < n_caps; ++c) {
         // Init buffer for events.
-        initEventsBuf(&capEventBuf[c], EVENT_LOG_SIZE);
+        initEventsBuf(&capEventBuf[c], EVENT_LOG_SIZE, c);
     }
-    initEventsBuf(&eventBuf, EVENT_LOG_SIZE);
+    initEventsBuf(&eventBuf, EVENT_LOG_SIZE, (EventCapNo)(-1));
 
     // Write in buffer: the header begin marker.
     postInt32(&eventBuf, EVENT_HEADER_BEGIN);
@@ -215,19 +250,38 @@ initEventLogging(void)
         case EVENT_THREAD_RUNNABLE: // (cap, thread)
         case EVENT_RUN_SPARK:       // (cap, thread)
         case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
-            eventTypes[t].size = sizeof(EventCapNo) + sizeof(EventThreadID);
+            eventTypes[t].size = sizeof(EventThreadID);
             break;
 
         case EVENT_MIGRATE_THREAD:  // (cap, thread, new_cap)
         case EVENT_STEAL_SPARK:     // (cap, thread, victim_cap)
         case EVENT_THREAD_WAKEUP:   // (cap, thread, other_cap)
             eventTypes[t].size =
-                sizeof(EventCapNo) + sizeof(EventThreadID) + sizeof(EventCapNo);
+                sizeof(EventThreadID) + sizeof(EventCapNo);
             break;
 
         case EVENT_STOP_THREAD:     // (cap, thread, status)
             eventTypes[t].size =
-                sizeof(EventCapNo) + sizeof(EventThreadID) + sizeof(StgWord16);
+                sizeof(EventThreadID) + sizeof(StgWord16) + sizeof(EventThreadID);
+            break;
+
+        case EVENT_STARTUP:         // (cap count)
+            eventTypes[t].size = sizeof(EventCapNo);
+            break;
+
+        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;
 
         case EVENT_SHUTDOWN:        // (cap)
@@ -235,20 +289,20 @@ initEventLogging(void)
         case EVENT_REQUEST_PAR_GC:  // (cap)
         case EVENT_GC_START:        // (cap)
         case EVENT_GC_END:          // (cap)
-            eventTypes[t].size = sizeof(EventCapNo);
+        case EVENT_GC_IDLE:
+        case EVENT_GC_WORK:
+        case EVENT_GC_DONE:
+            eventTypes[t].size = 0;
             break;
 
         case EVENT_LOG_MSG:          // (msg)
-        case EVENT_LOG_CAP_MSG:      // (cap,msg)
+        case EVENT_USER_MSG:         // (msg)
             eventTypes[t].size = 0xffff;
             break;
 
-        case EVENT_STARTUP:
-            eventTypes[t].size = sizeof(EventCapNo);
-            break;
-
         case EVENT_BLOCK_MARKER:
-            eventTypes[t].size = sizeof(StgWord32) + sizeof(EventTimestamp);
+            eventTypes[t].size = sizeof(StgWord32) + sizeof(EventTimestamp) + 
+                sizeof(EventCapNo);
             break;
 
         default:
@@ -267,7 +321,7 @@ initEventLogging(void)
     
     // Prepare event buffer for events (data).
     postInt32(&eventBuf, EVENT_DATA_BEGIN);
-    
+
     // Flush capEventBuf with header.
     /*
      * Flush header and data begin marker to the file, thus preparing the
@@ -278,6 +332,10 @@ initEventLogging(void)
     for (c = 0; c < n_caps; ++c) {
         postBlockMarker(&capEventBuf[c]);
     }
+
+#ifdef THREADED_RTS
+    initMutex(&eventBufMutex);
+#endif
 }
 
 void
@@ -290,6 +348,7 @@ endEventLogging(void)
         printAndClearEventBuf(&capEventBuf[c]);
     }
     printAndClearEventBuf(&eventBuf);
+    resetEventsBuf(&eventBuf); // we don't want the block marker
 
     // Mark end of events (data).
     postEventTypeNum(&eventBuf, EVENT_DATA_END);
@@ -320,6 +379,22 @@ freeEventLogging(void)
     }
 }
 
+void 
+flushEventLog(void)
+{
+    if (event_log_file != NULL) {
+        fflush(event_log_file);
+    }
+}
+
+void 
+abortEventLogging(void)
+{
+    freeEventLogging();
+    if (event_log_file != NULL) {
+        fclose(event_log_file);
+    }
+}
 /*
  * Post an event message to the capability's eventlog buffer.
  * If the buffer is full, prints out the buffer and clears it.
@@ -328,7 +403,8 @@ void
 postSchedEvent (Capability *cap, 
                 EventTypeNum tag, 
                 StgThreadID thread, 
-                StgWord64 other)
+                StgWord info1,
+                StgWord info2)
 {
     EventsBuf *eb;
 
@@ -340,7 +416,6 @@ postSchedEvent (Capability *cap,
     }
     
     postEventHeader(eb, tag);
-    postCapNo(eb, cap->no);
 
     switch (tag) {
     case EVENT_CREATE_THREAD:   // (cap, thread)
@@ -354,7 +429,7 @@ postSchedEvent (Capability *cap,
 
     case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
     {
-        postThreadID(eb,other /* spark_thread */);
+        postThreadID(eb,info1 /* spark_thread */);
         break;
     }
 
@@ -363,14 +438,15 @@ postSchedEvent (Capability *cap,
     case EVENT_THREAD_WAKEUP:   // (cap, thread, other_cap)
     {
         postThreadID(eb,thread);
-        postCapNo(eb,other /* new_cap | victim_cap | other_cap */);
+        postCapNo(eb,info1 /* new_cap | victim_cap | other_cap */);
         break;
    }
 
     case EVENT_STOP_THREAD:     // (cap, thread, status)
     {
         postThreadID(eb,thread);
-        postWord16(eb,other /* status */);
+        postWord16(eb,info1 /* status */);
+        postThreadID(eb,info2 /* blocked on thread */);
         break;
     }
 
@@ -388,11 +464,64 @@ postSchedEvent (Capability *cap,
     }
 }
 
-#define BUF 512
+void postCapsetModifyEvent (EventTypeNum tag,
+                            EventCapsetID capset,
+                            StgWord32 other)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
 
-void postMsg(char *msg, va_list ap)
+    if (!hasRoomForEvent(&eventBuf, tag)) {
+        // Flush event buffer to make room for new event.
+        printAndClearEventBuf(&eventBuf);
+    }
+
+    postEventHeader(&eventBuf, tag);
+    postCapsetID(&eventBuf, capset);
+
+    switch (tag) {
+    case EVENT_CAPSET_CREATE:   // (capset, capset_type)
+    {
+        postCapsetType(&eventBuf, other /* capset_type */);
+        break;
+    }
+
+    case EVENT_CAPSET_DELETE:   // (capset)
+    {
+        break;
+    }
+
+    case EVENT_CAPSET_ASSIGN_CAP:  // (capset, capno)
+    case EVENT_CAPSET_REMOVE_CAP:  // (capset, capno)
+    {
+        postCapNo(&eventBuf, other /* capno */);
+        break;
+    }
+    default:
+        barf("postCapsetModifyEvent: unknown event tag %d", tag);
+    }
+
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+void
+postEvent (Capability *cap, EventTypeNum tag)
 {
     EventsBuf *eb;
+
+    eb = &capEventBuf[cap->no];
+
+    if (!hasRoomForEvent(eb, tag)) {
+        // Flush event buffer to make room for new event.
+        printAndClearEventBuf(eb);
+    }
+
+    postEventHeader(eb, tag);
+}
+
+#define BUF 512
+
+void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap)
+{
     char buf[BUF];
     nat size;
 
@@ -402,53 +531,63 @@ void postMsg(char *msg, va_list ap)
         size = BUF;
     }
 
-    ACQUIRE_LOCK(&eventBufMutex);
-    eb = &eventBuf;
-
     if (!hasRoomForVariableEvent(eb, size)) {
         // Flush event buffer to make room for new event.
         printAndClearEventBuf(eb);
     }
 
-    postEventHeader(eb, EVENT_LOG_MSG);
+    postEventHeader(eb, type);
     postPayloadSize(eb, size);
     postBuf(eb,(StgWord8*)buf,size);
+}
 
+void postMsg(char *msg, va_list ap)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    postLogMsg(&eventBuf, EVENT_LOG_MSG, msg, ap);
     RELEASE_LOCK(&eventBufMutex);
 }
 
 void postCapMsg(Capability *cap, char *msg, va_list ap)
 {
-    EventsBuf *eb;
-    char buf[BUF];
-    nat size;
+    postLogMsg(&capEventBuf[cap->no], EVENT_LOG_MSG, msg, ap);
+}
 
-    size = vsnprintf(buf,BUF,msg,ap);
-    if (size > BUF) {
-        buf[BUF-1] = '\0';
-        size = BUF;
-    }
+void postUserMsg(Capability *cap, char *msg, va_list ap)
+{
+    postLogMsg(&capEventBuf[cap->no], EVENT_USER_MSG, msg, ap);
+}    
 
-    eb = &capEventBuf[cap->no];
+void postEventStartup(EventCapNo n_caps)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
 
-    if (!hasRoomForVariableEvent(eb, size)) {
+    if (!hasRoomForEvent(&eventBuf, EVENT_STARTUP)) {
         // Flush event buffer to make room for new event.
-        printAndClearEventBuf(eb);
+        printAndClearEventBuf(&eventBuf);
     }
 
-    postEventHeader(eb, EVENT_LOG_MSG);
-    postPayloadSize(eb, size + sizeof(EventCapNo));
-    postCapNo(eb, cap->no);
-    postBuf(eb,(StgWord8*)buf,size);
+    // Post a STARTUP event with the number of capabilities
+    postEventHeader(&eventBuf, EVENT_STARTUP);
+    postCapNo(&eventBuf, n_caps);
+
+    RELEASE_LOCK(&eventBufMutex);
 }
 
 void closeBlockMarker (EventsBuf *ebuf)
 {
+    StgInt8* save_pos;
+
     if (ebuf->marker)
     {
         // (type:16, time:64, size:32, end_time:64)
-        *(StgWord32 *)(ebuf->marker + 10) = ebuf->pos - ebuf->marker;
-        *(StgWord64 *)(ebuf->marker + 14) = time_ns();
+
+        save_pos = ebuf->pos;
+        ebuf->pos = ebuf->marker + sizeof(EventTypeNum) +
+                    sizeof(EventTimestamp);
+        postWord32(ebuf, save_pos - ebuf->marker);
+        postTimestamp(ebuf);
+        ebuf->pos = save_pos;
         ebuf->marker = NULL;
     }
 }
@@ -466,6 +605,7 @@ void postBlockMarker (EventsBuf *eb)
     postEventHeader(eb, EVENT_BLOCK_MARKER);
     postWord32(eb,0); // these get filled in later by closeBlockMarker();
     postWord64(eb,0);
+    postCapNo(eb, eb->capno);
 }
 
 void printAndClearEventBuf (EventsBuf *ebuf)
@@ -493,16 +633,18 @@ void printAndClearEventBuf (EventsBuf *ebuf)
     }
 }
 
-void initEventsBuf(EventsBuf* eb, StgWord64 size)
+void initEventsBuf(EventsBuf* eb, StgWord64 size, EventCapNo capno)
 {
     eb->begin = eb->pos = stgMallocBytes(size, "initEventsBuf");
     eb->size = size;
     eb->marker = NULL;
+    eb->capno = capno;
 }
 
 void resetEventsBuf(EventsBuf* eb)
 {
     eb->pos = eb->begin;
+    eb->marker = NULL;
 }
 
 StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum)