Don't truncate traceEvents to 512 bytes (#8309)
authorThomas Miedema <thomasmiedema@gmail.com>
Tue, 17 Feb 2015 14:39:08 +0000 (08:39 -0600)
committerAustin Seipp <austin@well-typed.com>
Tue, 17 Feb 2015 15:06:11 +0000 (09:06 -0600)
Summary:
Don't call postLogMsg to post a user msg, because it truncates messages to
512 bytes.

Rename traceCap_stderr and trace_stderr to vtraceCap_stderr and trace_stderr,
to signal that they take a va_list (similar to vdebugBelch vs debugBelch).

See #3874 for the original reason behind traceFormatUserMsg.

See the commit msg in #9395 (d360d440) for a discussion about using
null-terminated strings vs strings with an explicit length.

Test Plan:
Run `cabal install ghc-events` and inspect the result of `ghc-events show` on
an eventlog file created with `ghc -eventlog Test.hs` and `./Test +RTS -l`,
where Test.hs contains:

```
import Debug.Trace
main = traceEvent (replicate 510 'a' ++ "bcd") $ return ()
```

Depends on D655.

Reviewers: austin

Reviewed By: austin

Subscribers: thomie

Differential Revision: https://phabricator.haskell.org/D656

GHC Trac Issues: #8309

rts/Trace.c
rts/eventlog/EventLog.c
rts/eventlog/EventLog.h
testsuite/tests/rts/traceEvent.hs

index a0783f3..bd4d332 100644 (file)
@@ -622,7 +622,7 @@ void traceTaskDelete_ (Task *task)
 }
 
 #ifdef DEBUG
-static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
+static void vtraceCap_stderr(Capability *cap, char *msg, va_list ap)
 {
     ACQUIRE_LOCK(&trace_utx);
 
@@ -633,6 +633,14 @@ static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
 
     RELEASE_LOCK(&trace_utx);
 }
+
+static void traceCap_stderr(Capability *cap, char *msg, ...)
+{
+  va_list ap;
+  va_start(ap,msg);
+  vtraceCap_stderr(cap, msg, ap);
+  va_end(ap);
+}
 #endif
 
 void traceCap_(Capability *cap, char *msg, ...)
@@ -642,7 +650,7 @@ void traceCap_(Capability *cap, char *msg, ...)
 
 #ifdef DEBUG
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
-        traceCap_stderr(cap, msg, ap);
+        vtraceCap_stderr(cap, msg, ap);
     } else
 #endif
     {
@@ -653,7 +661,7 @@ void traceCap_(Capability *cap, char *msg, ...)
 }
 
 #ifdef DEBUG
-static void trace_stderr(char *msg, va_list ap)
+static void vtrace_stderr(char *msg, va_list ap)
 {
     ACQUIRE_LOCK(&trace_utx);
 
@@ -672,7 +680,7 @@ void trace_(char *msg, ...)
 
 #ifdef DEBUG
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
-        trace_stderr(msg, ap);
+        vtrace_stderr(msg, ap);
     } else
 #endif
     {
@@ -682,32 +690,24 @@ void trace_(char *msg, ...)
     va_end(ap);
 }
 
-static void traceFormatUserMsg(Capability *cap, char *msg, ...)
+void traceUserMsg(Capability *cap, char *msg)
 {
-    va_list ap;
-    va_start(ap,msg);
-
     /* Note: normally we don't check the TRACE_* flags here as they're checked
        by the wrappers in Trace.h. But traceUserMsg is special since it has no
        wrapper (it's called from cmm code), so we check TRACE_user here
      */
 #ifdef DEBUG
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_user) {
-        traceCap_stderr(cap, msg, ap);
+        // Use "%s" as format string to ignore format specifiers in msg (#3874).
+        traceCap_stderr(cap, "%s", msg);
     } else
 #endif
     {
         if (eventlog_enabled && TRACE_user) {
-            postUserMsg(cap, msg, ap);
+            postUserEvent(cap, EVENT_USER_MSG, msg);
         }
     }
     dtraceUserMsg(cap->no, msg);
-    va_end(ap);
-}
-
-void traceUserMsg(Capability *cap, char *msg)
-{
-    traceFormatUserMsg(cap, "%s", msg);
 }
 
 void traceUserMarker(Capability *cap, char *markername)
@@ -717,15 +717,12 @@ void traceUserMarker(Capability *cap, char *markername)
      */
 #ifdef DEBUG
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_user) {
-        ACQUIRE_LOCK(&trace_utx);
-        tracePreface();
-        debugBelch("cap %d: User marker: %s\n", cap->no, markername);
-        RELEASE_LOCK(&trace_utx);
+        traceCap_stderr(cap, "User marker: %s", markername);
     } else
 #endif
     {
         if (eventlog_enabled && TRACE_user) {
-            postUserMarker(cap, markername);
+            postUserEvent(cap, EVENT_USER_MARKER, markername);
         }
     }
     dtraceUserMarker(cap->no, markername);
index f830ec1..5f021a6 100644 (file)
@@ -1078,11 +1078,6 @@ void postCapMsg(Capability *cap, char *msg, va_list ap)
     postLogMsg(&capEventBuf[cap->no], EVENT_LOG_MSG, msg, ap);
 }
 
-void postUserMsg(Capability *cap, char *msg, va_list ap)
-{
-    postLogMsg(&capEventBuf[cap->no], EVENT_USER_MSG, msg, ap);
-}
-
 void postEventStartup(EventCapNo n_caps)
 {
     ACQUIRE_LOCK(&eventBufMutex);
@@ -1099,10 +1094,10 @@ void postEventStartup(EventCapNo n_caps)
     RELEASE_LOCK(&eventBufMutex);
 }
 
-void postUserMarker(Capability *cap, char *markername)
+void postUserEvent(Capability *cap, EventTypeNum type, char *msg)
 {
     EventsBuf *eb;
-    int size = strlen(markername);
+    int size = strlen(msg);
 
     eb = &capEventBuf[cap->no];
 
@@ -1115,9 +1110,9 @@ void postUserMarker(Capability *cap, char *markername)
         }
     }
 
-    postEventHeader(eb, EVENT_USER_MARKER);
+    postEventHeader(eb, type);
     postPayloadSize(eb, size);
-    postBuf(eb, (StgWord8*) markername, size);
+    postBuf(eb, (StgWord8*) msg, size);
 }
 
 void postThreadLabel(Capability    *cap,
index 85370e9..9c2f265 100644 (file)
@@ -45,12 +45,10 @@ void postEventAtTimestamp (Capability *cap, EventTimestamp ts,
 
 void postMsg(char *msg, va_list ap);
 
-void postUserMsg(Capability *cap, char *msg, va_list ap);
+void postUserEvent(Capability *cap, EventTypeNum type, char *msg);
 
 void postCapMsg(Capability *cap, char *msg, va_list ap);
 
-void postUserMarker(Capability *cap, char *markername);
-
 void postEventStartup(EventCapNo n_caps);
 
 /*
index ef64181..a5e19a9 100644 (file)
@@ -1,5 +1,5 @@
-import GHC.Exts
+import Debug.Trace
 
 main = do
-  traceEvent "testing"
-  traceEvent "%s" -- see #3874
+  traceEventIO "testing"
+  traceEventIO "%s" -- see #3874