
#11950: Eventlog should include delimiters showing when the process writes to the .eventlog file -------------------------------------+------------------------------------- Reporter: JamesFisher | Owner: Type: feature | Status: new request | Priority: normal | Milestone: Component: Runtime | Version: 7.10.3 System | Keywords: | Operating System: Unknown/Multiple Architecture: | Type of failure: None/Unknown Unknown/Multiple | Test Case: | Blocked By: Blocking: | Related Tickets: Differential Rev(s): | Wiki Page: -------------------------------------+------------------------------------- Quoting a comment I just added at https://ghc.haskell.org/trac/ghc/wiki/EventLog#Limitations :
Event logging can produce "observer effects". In particular, programs can pause while writing to the `.eventlog` file. These display in Threadscope as periods of 100% CPU use with no obvious cause. This effect is exacerbated by heavy use of debug tools which expand the eventlog file, such as `Trace.traceMarkerIO`. (This effect was at least seen on OS X. In an extreme case, a program doing nothing but writing 200,000 trace markers, which took 120 ms to run, showed a single 10ms pause in the middle to write them to the `.eventlog` file. These periods were shown to be due to writing the `.eventlog` file by using `dtruss -a`, which shows long periods of `write_nocancel` syscalls, writing to the `.eventlog` file opened earlier with `open_nocancel`.)
This behavior caused a few hours of investigation for us. It would make it much more obvious what is happening if this behavior were logged in the eventlog. Specifically, I would like for the eventlog to include a "starting writing eventlog file" event at the start of each of these periods, and a "stopped" event at the end of each period. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/11950 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler