delta/go-git.git/src/internal/trace, branch dev.debug github.com: golang/go runtime: record swept and reclaimed bytes in sweep trace 2017-04-19T18:31:14+00:00 Austin Clements austin@google.com 2017-04-14T18:44:22+00:00 22000f54073985958457168e8e19afa19e97821d This extends the GCSweepDone event with counts of swept and reclaimed bytes. These are useful for understanding the duration and effectiveness of sweep events. Change-Id: I3c97a4f0f3aad3adbd188adb264859775f54e2df Reviewed-on: https://go-review.googlesource.com/40811 Run-TryBot: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com> 
This extends the GCSweepDone event with counts of swept and reclaimed
bytes. These are useful for understanding the duration and
effectiveness of sweep events.

Change-Id: I3c97a4f0f3aad3adbd188adb264859775f54e2df
Reviewed-on: https://go-review.googlesource.com/40811
Run-TryBot: Austin Clements <austin@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
cmd/trace: Record mark assists in execution traces 2017-02-10T18:03:42+00:00 Heschi Kreinick heschi@google.com 2017-01-31T19:09:14+00:00 2a74b9e81405e34c67880866552b5d7bcab74de1 During the mark phase of garbage collection, goroutines that allocate may be recruited to assist. This change creates trace events for mark assists and displays them similarly to sweep assists in the trace viewer. Mark assists are different than sweeps in that they can be preempted, so displaying them in the trace viewer is a little tricky -- we may need to synthesize multiple slices for one mark assist. This could have been done in the parser instead, but I thought it might be preferable to keep the parser as true to the event stream as possible. Change-Id: I381dcb1027a187a354b1858537851fa68a620ea7 Reviewed-on: https://go-review.googlesource.com/36015 Run-TryBot: Heschi Kreinick <heschi@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Austin Clements <austin@google.com> Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com> 
During the mark phase of garbage collection, goroutines that allocate
may be recruited to assist. This change creates trace events for mark
assists and displays them similarly to sweep assists in the trace
viewer.

Mark assists are different than sweeps in that they can be preempted, so
displaying them in the trace viewer is a little tricky -- we may need to
synthesize multiple slices for one mark assist. This could have been
done in the parser instead, but I thought it might be preferable to keep
the parser as true to the event stream as possible.

Change-Id: I381dcb1027a187a354b1858537851fa68a620ea7
Reviewed-on: https://go-review.googlesource.com/36015
Run-TryBot: Heschi Kreinick <heschi@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Austin Clements <austin@google.com>
Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
runtime/trace, internal/trace: script to collect canned traces 2016-10-28T17:46:49+00:00 Austin Clements austin@google.com 2016-10-28T14:53:41+00:00 e14b02197737a0d7e5eed2856806cf20c85052cf This adds support to the runtime/trace test for saving traces collected by its tests to disk and a script in internal/trace that uses this to collect canned traces for the trace test suite. This can be used to add to the test suite when we introduce a new trace format version. Change-Id: Id9ac1ff312235bf02f982fdfff8a827f54035758 Reviewed-on: https://go-review.googlesource.com/32290 Run-TryBot: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Dmitry Vyukov <dvyukov@google.com> 
This adds support to the runtime/trace test for saving traces
collected by its tests to disk and a script in internal/trace that
uses this to collect canned traces for the trace test suite. This can
be used to add to the test suite when we introduce a new trace format
version.

Change-Id: Id9ac1ff312235bf02f982fdfff8a827f54035758
Reviewed-on: https://go-review.googlesource.com/32290
Run-TryBot: Austin Clements <austin@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
runtime, cmd/trace: track goroutines blocked on GC assists 2016-10-28T14:29:47+00:00 Austin Clements austin@google.com 2016-10-08T22:38:35+00:00 6da83c6fc006019f6fe0503099d165e19f465b1b Currently when a goroutine blocks on a GC assist, it emits a generic EvGoBlock event. Since assist blocking events and, in particular, the length of the blocked assist queue, are important for diagnosing GC behavior, this commit adds a new EvGoBlockGC event for blocking on a GC assist. The trace viewer uses this event to report a "waiting on GC" count in the "Goroutines" row. This makes sense because, unlike other blocked goroutines, these goroutines do have work to do, so being blocked on a GC assist is quite similar to being in the "runnable" state, which we also report in the trace viewer. Change-Id: Ic21a326992606b121ea3d3d00110d8d1fdc7a5ef Reviewed-on: https://go-review.googlesource.com/30704 Run-TryBot: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Dmitry Vyukov <dvyukov@google.com> 
Currently when a goroutine blocks on a GC assist, it emits a generic
EvGoBlock event. Since assist blocking events and, in particular, the
length of the blocked assist queue, are important for diagnosing GC
behavior, this commit adds a new EvGoBlockGC event for blocking on a
GC assist. The trace viewer uses this event to report a "waiting on
GC" count in the "Goroutines" row. This makes sense because, unlike
other blocked goroutines, these goroutines do have work to do, so
being blocked on a GC assist is quite similar to being in the
"runnable" state, which we also report in the trace viewer.

Change-Id: Ic21a326992606b121ea3d3d00110d8d1fdc7a5ef
Reviewed-on: https://go-review.googlesource.com/30704
Run-TryBot: Austin Clements <austin@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
runtime, cmd/trace: annotate different mark worker types 2016-10-28T14:29:40+00:00 Austin Clements austin@google.com 2016-10-07T21:25:26+00:00 68348394274ee83f5286022d97cfe58b6761321b Currently mark workers are shown in the trace as regular goroutines labeled "runtime.gcBgMarkWorker". That's somewhat unhelpful to an end user because of the opaque label and particularly unhelpful to runtime developers because it doesn't distinguish the different types of mark workers. Fix this by introducing a variant of the GoStart event called GoStartLabel that lets the runtime indicate a label for a goroutine execution span and using this to label mark worker executions as "GC (<mode>)" in the trace viewer. Since this bumps the trace version to 1.8, we also add test data for 1.7 traces. Change-Id: Id7b9c0536508430c661ffb9e40e436f3901ca121 Reviewed-on: https://go-review.googlesource.com/30702 Run-TryBot: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Dmitry Vyukov <dvyukov@google.com> 
Currently mark workers are shown in the trace as regular goroutines
labeled "runtime.gcBgMarkWorker". That's somewhat unhelpful to an end
user because of the opaque label and particularly unhelpful to runtime
developers because it doesn't distinguish the different types of mark
workers.

Fix this by introducing a variant of the GoStart event called
GoStartLabel that lets the runtime indicate a label for a goroutine
execution span and using this to label mark worker executions as "GC
(<mode>)" in the trace viewer.

Since this bumps the trace version to 1.8, we also add test data for
1.7 traces.

Change-Id: Id7b9c0536508430c661ffb9e40e436f3901ca121
Reviewed-on: https://go-review.googlesource.com/30702
Run-TryBot: Austin Clements <austin@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
cmd/trace: fix a runnable goroutine count bug 2016-10-11T12:07:44+00:00 Hyang-Ah (Hana) Kim hyangah@gmail.com 2016-08-08T21:24:07+00:00 c24cc40075d77b96bbf1f217dcdcff651229e89b When starting tracing, EvGoCreate events are added for existing goroutines that may have been blocking in syscall. EvGoCreate increments the runnable goroutine count. This change makes the following EvGoInSyscall event decrement the runnable goroutine count because we now know that goroutine is in syscall, and not runnable. Made generateTrace return an error, at any given time, the number of runnable/running/insyscall goroutines becomes non-negative. Added a basic test that checks the number of runnable/running goroutines don't include the goroutines in syscall - the test failed before this change. Change-Id: Ib732c382e7bd17158a437576f9d589ab89097ce6 Reviewed-on: https://go-review.googlesource.com/25552 Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Dmitry Vyukov <dvyukov@google.com> 
When starting tracing, EvGoCreate events are added for existing
goroutines that may have been blocking in syscall. EvGoCreate
increments the runnable goroutine count. This change makes the
following EvGoInSyscall event decrement the runnable goroutine count
because we now know that goroutine is in syscall, and not runnable.

Made generateTrace return an error, at any given time, the number
of runnable/running/insyscall goroutines becomes non-negative.

Added a basic test that checks the number of runnable/running
goroutines don't include the goroutines in syscall - the test failed
before this change.

Change-Id: Ib732c382e7bd17158a437576f9d589ab89097ce6
Reviewed-on: https://go-review.googlesource.com/25552
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
cmd/trace: label mark termination spans as such 2016-10-07T18:33:23+00:00 Austin Clements austin@google.com 2016-09-29T15:59:56+00:00 94589054d3ed88c049fbe468d58b995e0e154f1d Currently these are labeled "MARK", which was accurate in the STW collector, but these really indicate mark termination now, since marking happens for the full duration of the concurrent GC. Re-label them as "MARK TERMINATION" to clarify this. Change-Id: Ie98bd961195acde49598b4fa3f9e7d90d757c0a6 Reviewed-on: https://go-review.googlesource.com/30018 Reviewed-by: Dmitry Vyukov <dvyukov@google.com> 
Currently these are labeled "MARK", which was accurate in the STW
collector, but these really indicate mark termination now, since
marking happens for the full duration of the concurrent GC. Re-label
them as "MARK TERMINATION" to clarify this.

Change-Id: Ie98bd961195acde49598b4fa3f9e7d90d757c0a6
Reviewed-on: https://go-review.googlesource.com/30018
Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
cmd/trace: move process-wide GC events to their own row 2016-10-07T18:33:12+00:00 Austin Clements austin@google.com 2016-09-29T15:53:42+00:00 eed309f5fb223a879630e9dced8c44c2b049cf71 Currently, the process-wide GC state is attributed to the P that happened to perform the allocation that exceeded the GC trigger. This is pretty arbitrary and makes it hard to see when GC is running since the GC spans are intermingled with a lot of other trace noise. The current display is particularly confusing because it creates three sub-rows in the P row that can overlap each other. Usually a P has just two sub-rows: one showing the current G and another showing that G's activity. However, because GC is attributed to a proc, it winds up as a third row that neither subsumes nor is subsumed by any other row. This in turn screws up the trace's layout and results in overlapping events. Fix these problems by creating a new dedicated row like the existing "Network" and "Timer" rows and displaying process-wide GC events in this row. Mark termination and sweep events still appear in their respective P rows because these are meaningfully attributed. Change-Id: Ie1a1c6cf8c446e4b043f10f3968f91ff1b546d15 Reviewed-on: https://go-review.googlesource.com/30017 Reviewed-by: Dmitry Vyukov <dvyukov@google.com> 
Currently, the process-wide GC state is attributed to the P that
happened to perform the allocation that exceeded the GC trigger. This
is pretty arbitrary and makes it hard to see when GC is running since
the GC spans are intermingled with a lot of other trace noise.

The current display is particularly confusing because it creates three
sub-rows in the P row that can overlap each other. Usually a P has
just two sub-rows: one showing the current G and another showing that
G's activity. However, because GC is attributed to a proc, it winds up
as a third row that neither subsumes nor is subsumed by any other row.
This in turn screws up the trace's layout and results in overlapping
events.

Fix these problems by creating a new dedicated row like the existing
"Network" and "Timer" rows and displaying process-wide GC events in
this row. Mark termination and sweep events still appear in their
respective P rows because these are meaningfully attributed.

Change-Id: Ie1a1c6cf8c446e4b043f10f3968f91ff1b546d15
Reviewed-on: https://go-review.googlesource.com/30017
Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
internal/trace: fix analysis of EvGoWaiting/EvGoInSyscall events 2016-08-19T19:22:17+00:00 Dmitry Vyukov dvyukov@google.com 2016-08-08T13:41:18+00:00 a50f9859bd15784d047875624c9fa91ce69bd85b When tracing is started in the middle of program execution, we already have a number of runnable goroutines and a number of blocked/in syscall goroutines. In order to reflect these goroutines in the trace, we emit EvGoCreate for all existing goroutines. Then for blocked/in syscall goroutines we additionally emit EvGoWaiting/EvGoInSyscall events. These events don't reset g.ev during trace analysis. So next EvGoStart finds g.ev set to the previous EvGoCreate. As the result time between EvGoCreate and EvGoStart is accounted as scheduler latency. While in reality it is blocking/syscall time. Properly reset g.ev for EvGoWaiting/EvGoInSyscall events. Change-Id: I0615ba31ed7567600a0667ebb27458481da73adb Reviewed-on: https://go-review.googlesource.com/25572 Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com> 
When tracing is started in the middle of program execution,
we already have a number of runnable goroutines and a number
of blocked/in syscall goroutines. In order to reflect these
goroutines in the trace, we emit EvGoCreate for all existing
goroutines. Then for blocked/in syscall goroutines we additionally
emit EvGoWaiting/EvGoInSyscall events. These events don't reset g.ev
during trace analysis. So next EvGoStart finds g.ev set to the
previous EvGoCreate. As the result time between EvGoCreate and
EvGoStart is accounted as scheduler latency. While in reality
it is blocking/syscall time.

Properly reset g.ev for EvGoWaiting/EvGoInSyscall events.

Change-Id: I0615ba31ed7567600a0667ebb27458481da73adb
Reviewed-on: https://go-review.googlesource.com/25572
Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
internal/trace: err if binary is not supplied for old trace 2016-06-16T16:22:03+00:00 Hana Kim hyangah@gmail.com 2016-06-15T16:53:05+00:00 c3818e56d0f60493a63b2bb03a09f261d3e0ada2 Change-Id: Id25c90993c4cbb7449d7031301b6d214a67d7633 Reviewed-on: https://go-review.googlesource.com/24134 Reviewed-by: Dmitry Vyukov <dvyukov@google.com> Run-TryBot: Dmitry Vyukov <dvyukov@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> 
Change-Id: Id25c90993c4cbb7449d7031301b6d214a67d7633
Reviewed-on: https://go-review.googlesource.com/24134
Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
Run-TryBot: Dmitry Vyukov <dvyukov@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>