[GHC] #8309: traceEvent truncates to 512 bytes

#8309: traceEvent truncates to 512 bytes ------------------------------------+------------------------------------- Reporter: duncan | Owner: Type: bug | Status: new Priority: normal | Milestone: Component: Runtime System | Version: 7.6.3 Keywords: eventlog tracing | Operating System: Unknown/Multiple Architecture: Unknown/Multiple | Type of failure: None/Unknown Difficulty: Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | ------------------------------------+------------------------------------- The `Debug.Trace.traceEvent` (& `traceEventIO`) use a code path that unnecessarily uses printf format strings and uses a fixed size 512-byte buffer, hence truncating all user trace messages at that size. Here is the call path: * `Debug.Trace.traceEvent` (& `traceEventIO`) call `traceEvent#` primop * cmm impl of the primop `stg_traceEventzh` calls C RTS function `traceUserMsg` * `traceUserMsg` calls `traceFormatUserMsg(cap, "%s", msg);`, using the printf format string * `traceFormatUserMsg` uses `postUserMsg` which eventually calls `postLogMsg` * `postLogMsg` does the printf stuff Here's what `postLogMsg` does: {{{ #define BUF 512 void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap) { char buf[BUF]; nat size; size = vsnprintf(buf,BUF,msg,ap); if (size > BUF) { buf[BUF-1] = '\0'; size = BUF; } .... }}} This is obviously designed for RTS-internal users, not the user path. So the problem starts with this bit: {{{ void traceUserMsg(Capability *cap, char *msg) { traceFormatUserMsg(cap, "%s", msg); } }}} It just should not use that code path. It should call something that directly posts the message, without any silly printf strings. In fact, the code path from the primop down should really be changed to use an explicit given length, rather than using a null-terminated string and having to call strlen. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/8309 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#8309: traceEvent truncates to 512 bytes -------------------------------------+------------------------------------ Reporter: duncan | Owner: Type: bug | Status: new Priority: normal | Milestone: Component: Runtime System | Version: 7.6.3 Resolution: | Keywords: eventlog tracing Operating System: Unknown/Multiple | Architecture: Unknown/Multiple Type of failure: None/Unknown | Difficulty: Unknown Test Case: | Blocked By: Blocking: | Related Tickets: -------------------------------------+------------------------------------ Comment (by edsko): subscribe -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/8309#comment:1 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#8309: traceEvent truncates to 512 bytes -------------------------------------+------------------------------------- Reporter: duncan | Owner: Type: bug | Status: patch Priority: normal | Milestone: Component: Runtime System | Version: 7.6.3 Resolution: | Keywords: eventlog Operating System: Unknown/Multiple | tracing Type of failure: None/Unknown | Architecture: Blocked By: | Unknown/Multiple Related Tickets: #3874 | Test Case: | Blocking: | Differential Revisions: Phab:D656 -------------------------------------+------------------------------------- Changes (by thomie): * cc: simonmar (added) * status: new => patch * differential: => Phab:D656 * related: => #3874 Comment: I made `traceUserMsg` call `postUserMarker` (renamed to `postUserEvent`), which does not have the truncation problem. See the commit message in Trac #9395 (d360d440) for a discussion about using null-terminated strings vs strings with an explicit length. I did not make any change here. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/8309#comment:2 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#8309: traceEvent truncates to 512 bytes
-------------------------------------+-------------------------------------
Reporter: duncan | Owner:
Type: bug | Status: patch
Priority: normal | Milestone:
Component: Runtime System | Version: 7.6.3
Resolution: | Keywords: eventlog
Operating System: Unknown/Multiple | tracing
Type of failure: None/Unknown | Architecture:
Blocked By: | Unknown/Multiple
Related Tickets: #3874 | Test Case:
| Blocking:
| Differential Revisions: Phab:D656
-------------------------------------+-------------------------------------
Comment (by Austin Seipp

#8309: traceEvent truncates to 512 bytes -------------------------------------+------------------------------------- Reporter: duncan | Owner: Type: bug | Status: patch Priority: normal | Milestone: 7.12.1 Component: Runtime System | Version: 7.6.3 Resolution: | Keywords: eventlog Operating System: Unknown/Multiple | tracing Type of failure: None/Unknown | Architecture: Blocked By: | Unknown/Multiple Related Tickets: #3874 | Test Case: | Blocking: | Differential Revisions: Phab:D656 -------------------------------------+------------------------------------- Changes (by thoughtpolice): * milestone: => 7.12.1 Comment: Merged, thanks! -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/8309#comment:4 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#8309: traceEvent truncates to 512 bytes -------------------------------------+------------------------------------- Reporter: duncan | Owner: Type: bug | Status: closed Priority: normal | Milestone: 7.12.1 Component: Runtime System | Version: 7.6.3 Resolution: fixed | Keywords: eventlog Operating System: Unknown/Multiple | tracing Type of failure: None/Unknown | Architecture: Blocked By: | Unknown/Multiple Related Tickets: #3874 | Test Case: | Blocking: | Differential Revisions: Phab:D656 -------------------------------------+------------------------------------- Changes (by thoughtpolice): * status: patch => closed * resolution: => fixed -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/8309#comment:5 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler
participants (1)
-
GHC