| Commit message (Collapse) | Author | Age | Files | Lines |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
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
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Event log had inconcistent support for increacing capabilies
number, as header were not inserted in capability buffer. It
resulted in a ghc-events crash (see #9384). This commit
fixes this issue by inserting required header when number
of capabilies grows.
Reviewers: simonmar, Mikolaj, trofi, austin
Reviewed By: Mikolaj, trofi, austin
Subscribers: carter, thomie
Differential Revision: https://phabricator.haskell.org/D592
GHC Trac Issues: #9384
|
|
|
|
| |
This reverts commit 39b5c1cbd8950755de400933cecca7b8deb4ffcd.
|
| |
|
|
|
|
|
|
|
|
| |
This will hopefully help ensure some basic consistency in the forward by
overriding buffer variables. In particular, it sets the wrap length, the
offset to 4, and turns off tabs.
Signed-off-by: Austin Seipp <austin@well-typed.com>
|
|
|
|
| |
Signed-off-by: Austin Seipp <austin@well-typed.com>
|
|
|
|
|
|
|
| |
The TL;DR is that by adding this, we can distinguish GHC 7.8.3 from
7.8.2, which had a buggy implementation. See the ticket for details.
Signed-off-by: Austin Seipp <austin@well-typed.com>
|
|
|
|
|
|
|
| |
After a toolchain update, Clang is no longer appreciative of the fact
these are unused, thanks to -Werror during validate.
Signed-off-by: Austin Seipp <austin@well-typed.com>
|
|
|
|
|
|
|
|
|
| |
In time-based profiling visualisations (e.g. heap profiles and ThreadScope)
it would be useful to be able to mark particular points in the execution and
have those points in time marked in the visualisation.
The traceMarker# primop currently emits an event into the eventlog. In
principle it could be extended to do something in the heap profiling too.
|
|
|
|
|
|
|
|
|
|
|
|
| |
lnat was originally "long unsigned int" but we were using it when we
wanted a 64-bit type on a 64-bit machine. This broke on Windows x64,
where long == int == 32 bits. Using types of unspecified size is bad,
but what we really wanted was a type with N bits on an N-bit machine.
StgWord is exactly that.
lnat was mentioned in some APIs that clients might be using
(e.g. StackOverflowHook()), so we leave it defined but with a comment
to say that it's deprecated.
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Based on initial patches by Mikolaj Konarski <mikolaj@well-typed.com>
These new eventlog events are to let profiling tools keep track of all
the OS threads that belong to an RTS capability at any moment in time.
In the RTS, OS threads correspond to the Task abstraction, so that is
what we track. There are events for tasks being created, migrated
between capabilities and deleted. In particular the task creation event
also records the kernel thread id which lets us match up the OS thread
with data collected by others tools (in the initial use case with
Linux's perf tool, but in principle also with DTrace).
|
| |
|
|
|
|
| |
I've assumed that the definition type is right.
|
|
|
|
|
|
|
|
|
| |
Quoting design rationale by dcoutts: The event indicates that we're doing
a stop-the-world GC and all other HECs should be between their GC_START
and GC_END events at that moment. We don't want to use GC_STATS_GHC
for that, because GC_STATS_GHC is for extra GHC-specific info,
not something we have to rely on to be able to match the GC pauses
across HECs to a particular global GC.
|
|
|
|
|
|
|
|
|
|
|
| |
There was a discrepancy between GC times reported in +RTS -s
and the timestamps of GC_START and GC_END events on the cap,
on which +RTS -s stats for the given GC are based.
This is fixed by posting the events with exactly the same timestamp
as generated for the stat calculation. The calls posting the events
are moved too, so that the events are emitted close to the time instant
they claim to be emitted at. The GC_STATS_GHC was moved, too, ensuring
it's emitted before the moved GC_END on all caps, which simplifies tools code.
|
|
|
|
|
|
|
| |
The EventLogFormat.h described the spark counter fields in a different
order to that which ghc emits (the GC'd and fizzled fields were
reversed). At this stage it is easier to fix the ghc-events lib and
to have ghc continue to emit them in the current order.
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
They cover much the same info as is available via the GHC.Stats module
or via the '+RTS -s' textual output, but via the eventlog and with a
better sampling frequency.
We have three new generic heap info events and two very GHC-specific
ones. (The hope is the general ones are usable by other implementations
that use the same eventlog system, or indeed not so sensitive to changes
in GHC itself.)
The general ones are:
* total heap mem allocated since prog start, on a per-HEC basis
* current size of the heap (MBlocks reserved from OS for the heap)
* current size of live data in the heap
Currently these are all emitted by GHC at GC time (live data only at
major GC).
The GHC specific ones are:
* an event giving various static heap paramaters:
* number of generations (usually 2)
* max size if any
* nursary size
* MBlock and block sizes
* a event emitted on each GC containing:
* GC generation (usually just 0,1)
* total bytes copied
* bytes lost to heap slop and fragmentation
* the number of threads in the parallel GC (1 for serial)
* the maximum number of bytes copied by any par GC thread
* the total number of bytes copied by all par GC threads
(these last three can be used to calculate an estimate of the
work balance in parallel GCs)
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Now that we can adjust the number of capabilities on the fly, we need
this reflected in the eventlog. Previously the eventlog had a single
startup event that declared a static number of capabilities. Obviously
that's no good anymore.
For compatability we're keeping the EVENT_STARTUP but adding new
EVENT_CAP_CREATE/DELETE. The EVENT_CAP_DELETE is actually just the old
EVENT_SHUTDOWN but renamed and extended (using the existing mechanism
to extend eventlog events in a compatible way). So we now emit both
EVENT_STARTUP and EVENT_CAP_CREATE. One day we will drop EVENT_STARTUP.
Since reducing the number of capabilities at runtime does not really
delete them, it just disables them, then we also have new events for
disable/enable.
The old EVENT_SHUTDOWN was in the scheduler class of events. The new
EVENT_CAP_* events are in the unconditional class, along with the
EVENT_CAPSET_* ones. Knowing when capabilities are created and deleted
is crucial to making sense of eventlogs, you always want those events.
In any case, they're extremely low volume.
|
|
|
|
|
| |
At present the number of capabilities can only be *increased*, not
decreased. The latter presents a few more challenges!
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Terminology cleanup: the type "Ticks" has been renamed "Time", which
is an StgWord64 in units of TIME_RESOLUTION (currently nanoseconds).
The terminology "tick" is now used consistently to mean the interval
between timer signals.
The ticker now always ticks in realtime (actually CLOCK_MONOTONIC if
we have it). Before it used CPU time in the non-threaded RTS and
realtime in the threaded RTS, but I've discovered that the CPU timer
has terrible resolution (at least on Linux) and isn't much use for
profiling. So now we always use realtime. This should also fix
The default tick interval is now 10ms, except when profiling where we
drop it to 1ms. This gives more accurate profiles without affecting
runtime too much (<1%).
Lots of cleanups - the resolution of Time is now in one place
only (Rts.h) rather than having calculations that depend on the
resolution scattered all over the RTS. I hope I found them all.
|
|
|
|
| |
Fixes ticket #5472
|
|
|
|
|
|
| |
The existing GHC.Conc.labelThread will now also emit the the thread
label into the eventlog. Profiling tools like ThreadScope could then
use the thread labels rather than thread numbers.
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Eventlog timestamps are elapsed times (in nanoseconds) relative to the
process start. To be able to merge eventlogs from multiple processes we
need to be able to align their timelines. If they share a clock domain
(or a user judges that their clocks are sufficiently closely
synchronised) then it is sufficient to know how the eventlog timestamps
match up with the clock.
The EVENT_WALL_CLOCK_TIME contains the clock time with (up to)
nanosecond precision. It is otherwise an ordinary event and so contains
the usual timestamp for the same moment in time. It therefore enables
us to match up all the eventlog timestamps with clock time.
|
| |
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Replaces the existing EVENT_RUN/STEAL_SPARK events with 7 new events
covering all stages of the spark lifcycle:
create, dud, overflow, run, steal, fizzle, gc
The sampled spark events are still available. There are now two event
classes for sparks, the sampled and the fully accurate. They can be
enabled/disabled independently. By default +RTS -l includes the sampled
but not full detail spark events. Use +RTS -lf-p to enable the detailed
'f' and disable the sampled 'p' spark.
Includes work by Mikolaj <mikolaj.konarski@gmail.com>
|
|
|
|
|
|
|
| |
Previously GC was included in the scheduler trace class. It can be
enabled specifically with +RTS -vg or -lg, though note that both -v
and -l on their own now default to a sensible set of trace classes,
currently: scheduler, gc and sparks.
|
|
|
|
|
|
|
| |
A new eventlog event containing 7 spark counters/statistics: sparks
created, dud, overflowed, converted, GC'd, fizzled and remaining.
These are maintained and logged separately for each capability.
We log them at startup, on each GC (minor and major) and on shutdown.
|
|
|
|
|
| |
A missing ';' that just happened to work fine on non-windows due
to differing definitions of the ACQUIRE_LOCK macro.
|
|
|
|
|
| |
The process ID, parent process ID, rts name and version
The program arguments and environment.
|
|
|
|
|
|
|
| |
We trace the creation and shutdown of capabilities. All the capabilities
in the process are assigned to one capabilitiy set of OS-process type.
This is a second version of the patch. Includes work by Spencer Janssen.
|
|
|
|
| |
Rather than doing it differently for the eventlog and Dtrace cases.
|
|
|
|
|
|
|
|
| |
Coutts."
This reverts commit 58532eb46041aec8d4cbb48b054cb5b001edb43c.
Turns out it didn't work on Windows and it'll need some non-trivial changes
to make it work on Windows. We'll get it in later once that's sorted out.
|
| |
|
|
|
|
|
|
|
|
|
| |
So we can now get these in ThreadScope:
19487000: cap 1: stopping thread 6 (blocked on black hole owned by thread 4)
Note: needs an update to ghc-events. Older ThreadScopes will just
ignore the new information.
|
| |
|
|
|
|
| |
Schedule.c - uses them in forkProcess.
|
| |
|
| |
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
This replaces some complicated locking schemes with message-passing
in the implementation of throwTo. The benefits are
- previously it was impossible to guarantee that a throwTo from
a thread running on one CPU to a thread running on another CPU
would be noticed, and we had to rely on the GC to pick up these
forgotten exceptions. This no longer happens.
- the locking regime is simpler (though the code is about the same
size)
- threads can be unblocked from a blocked_exceptions queue without
having to traverse the whole queue now. It's a rare case, but
replaces an O(n) operation with an O(1).
- generally we move in the direction of sharing less between
Capabilities (aka HECs), which will become important with other
changes we have planned.
Also in this patch I replaced several STM-specific closure types with
a generic MUT_PRIM closure type, which allowed a lot of code in the GC
and other places to go away, hence the line-count reduction. The
message-passing changes resulted in about a net zero line-count
difference.
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
- Defines a DTrace provider, called 'HaskellEvent', that provides a probe
for every event of the eventlog framework.
- In contrast to the original eventlog, the DTrace probes are available in
all flavours of the runtime system (DTrace probes have virtually no
overhead if not enabled); when -DTRACING is defined both the regular
event log as well as DTrace probes can be used.
- Currently, Mac OS X only. User-space DTrace probes are implemented
differently on Mac OS X than in the original DTrace implementation.
Nevertheless, it shouldn't be too hard to enable these probes on other
platforms, too.
- Documentation is at http://hackage.haskell.org/trac/ghc/wiki/DTrace
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
added:
primop TraceEventOp "traceEvent#" GenPrimOp
Addr# -> State# s -> State# s
{ Emits an event via the RTS tracing framework. The contents
of the event is the zero-terminated byte string passed as the first
argument. The event will be emitted either to the .eventlog file,
or to stderr, depending on the runtime RTS flags. }
and added the required RTS functionality to support it. Also a bit of
refactoring in the RTS tracing code.
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
| |
This makes events smaller and tracing quicker, and speeds up reading
and sorting the trace file.
HEADS UP: this changes the format of event log files. Corresponding
changes to the ghc-events package are required (and will be pushed
soon). Normally we would make backwards-compatible changes, but this
changes the format of every event (to remove the capability) so I'm
breaking the rules this time. This will be the only time we can do
this, since the format becomes public in 6.12.1.
|
|
|
|
|
| |
These indicate the size and time span of a sequence of events in the
event log, to make it easier to sort and navigate a large event log.
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
- tracing facilities are now enabled with -DTRACING, and -DDEBUG
additionally enables debug-tracing. -DEVENTLOG has been
removed.
- -debug now implies -eventlog
- events can be printed to stderr instead of being sent to the
binary .eventlog file by adding +RTS -v (which is implied by the
+RTS -Dx options).
- -Dx debug messages can be sent to the binary .eventlog file
by adding +RTS -l. This should help debugging by reducing
the impact of debug tracing on execution time.
- Various debug messages that duplicated the information in events
have been removed.
|