runtime: add gctool

runtime: add gctool

See documentation in gctool.go

[atom, 2013-05-29 09:53:28]

Hello golang-dev@googlegroups.com (cc: dvyukov@google.com, rsc@golang.org),

I'd like you to review this change to
https://code.google.com/p/go/

[iant, 2013-05-29 18:21:08]

I think we should discuss this idea on golang-dev.

[0xe2.0x9a.0x9b_gmail.com, 2013-05-29 18:25:39]

Does the idea seem controversial or good?

On Wednesday, May 29, 2013 8:21:08 PM UTC+2, Ian Lance Taylor wrote:
>
> I think we should discuss this idea on golang-dev. 
>
>
> https://codereview.appspot.com/9666049/ 
>

[rsc, 2013-05-29 18:33:14]

The overall idea of having a tool to debug the garbage collector is fine,
but we should discuss the plan, in a different thread (not in this CL) and
include Carl. I have a similar tool that I never checked in because it is
really not something ordinary people can use. Whatever we do should be part
of a plan to benefit programmers who don't work on the garbage collector.

Russ

[dvyukov, 2013-05-30 06:36:18]

On 2013/05/29 09:53:28, atom wrote:
> Hello mailto:golang-dev@googlegroups.com (cc: mailto:dvyukov@google.com,
mailto:rsc@golang.org),
> 
> I'd like you to review this change to
> https://code.google.com/p/go/

Please post example log and output of the tool.

[dvyukov, 2013-05-30 06:38:17]

On 2013/05/29 18:33:14, rsc wrote:
> The overall idea of having a tool to debug the garbage collector is fine,
> but we should discuss the plan, in a different thread (not in this CL) and
> include Carl. I have a similar tool that I never checked in because it is
> really not something ordinary people can use. Whatever we do should be part
> of a plan to benefit programmers who don't work on the garbage collector.

I am not sure whether it will be useful for anything other than tiny programs.
Debugging GC issues requires really lots of information.

[atom, 2013-05-30 07:38:21]

On 2013/05/30 06:36:18, dvyukov wrote:
> On 2013/05/29 09:53:28, atom wrote:
> > Hello mailto:golang-dev@googlegroups.com (cc: mailto:dvyukov@google.com,
> mailto:rsc@golang.org),
> > 
> > I'd like you to review this change to
> > https://code.google.com/p/go/
> 
> Please post example log and output of the tool.

The below text has been obtained while working on code related to
https://code.google.com/p/go/issues/detail?id=5584. Absolute paths in function
names have been truncated to improve readability of the text. The interesting
parts in the output (not in the log) are lines with stackframe(f="addroots").

$ head -n20 log
#gctool gcbegin
#gctool datasection 0 0x8303100 0x6854
#gctool bsssection 0 0x8319ba0 0x3b6c
#gctool mark 0 0x1847c030 where=markonly
#gctool mark 0 0x1847c000 where=markonly
#gctool stackframe 0 0x18471284 0x24 where=A f="addroots"
#gctool stackframe 0 0x184712ac 0x12c where=A f="gc"
#gctool stackframe 0 0x184713dc 0x4 where=C f="gc"
#gctool stackframe 0 0xb7314a1c 0x1c where=A f="runtime.gc"
#gctool stackframe 0 0xb7314a3c 0x4 where=C f="runtime.gc"
#gctool stackframe 0 0xb7314a3c 0x2c where=A f="runtime.mallocgc"
#gctool stackframe 0 0xb7314a6c 0x10 where=C f="runtime.mallocgc"
#gctool stackframe 0 0xb7314a6c 0x14 where=A f="runtime.new"
#gctool stackframe 0 0xb7314a84 0x14 where=A f="errors.New"
#gctool stackframe 0 0xb7314a9c 0x10 where=C f="errors.New"
#gctool stackframe 0 0xb7314a9c 0x10 where=A f="strconv.init"
#gctool stackframe 0 0xb7314ab0 0x10 where=A f="reflect.init"
#gctool stackframe 0 0xb7314ac4 0x20 where=A f="fmt.init"
#gctool stackframe 0 0xb7314ae8 0x10 where=A f="compress/gzip.init"
#gctool stackframe 0 0xb7314b1c 0x4a0 where=B f="_/home/.../test/http.init"

$ cat output
====
====
====
====
====
====
====
backtrack main.Range{start:0x1852f000, size:0x2052efff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x1852f000 from backtrack
backtrack main.Range{start:0x2052f000, size:0x2852efff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x2052f000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x18521000 from backtrack
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x18521000 from backtrack
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x18521000 from backtrack
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="addroots") 0x18471284,0x24
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x184009f8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400a20,0x8
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="gc") 0x184712ac,0x12c
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x28521000, size:0x30520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x28521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400a90,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400ab8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400ae0,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400b50,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400b78,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400ba0,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x28521000, size:0x30520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x28521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400c10,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400c38,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400c60,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400cd0,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400cf8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400d20,0x8
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x28521000, size:0x30520fff}:
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x28521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x184001c8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400dc8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400e60,0x8
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x184004b8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x184004e0,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400510,0x8
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x28521000, size:0x30520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x28521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400580,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x184005a8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x184980c0,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400490,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18498040,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18498078,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x28521000, size:0x30520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x28521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x184001c8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400508,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400530,0x8
	stackframe(f="gc") 0x184712ac,0x12c
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x20521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400ca8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400dc8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400e60,0x8
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x28521000, size:0x30520fff}:
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
remove 0x28521000 from backtrack
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400be8,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400d18,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400d40,0x8
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
====
backtrack main.Range{start:0x18521000, size:0x20520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400b28,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400c58,0x8
	stackframe(f="test/http.API") 0xb6202d8c,0x100 ->  0x18400c80,0x8
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x20521000, size:0x28520fff}:
	stackframe(f="addroots") 0x18471284,0x24
	stackframe(f="test/http.API") 0xb6202d8c,0x100
backtrack main.Range{start:0x28521000, size:0x30520fff}:
	stackframe(f="test/http.API") 0xb6202d8c,0x100

[atom, 2013-05-30 07:49:58]

On 2013/05/30 06:38:17, dvyukov wrote:
> On 2013/05/29 18:33:14, rsc wrote:
> > The overall idea of having a tool to debug the garbage collector is fine,
> > but we should discuss the plan, in a different thread (not in this CL) and
> > include Carl. I have a similar tool that I never checked in because it is
> > really not something ordinary people can use. Whatever we do should be part
> > of a plan to benefit programmers who don't work on the garbage collector.
> 
> I am not sure whether it will be useful for anything other than tiny programs.
> Debugging GC issues requires really lots of information.

I agree.

On the other hand, examining the log generated when mgc0.c/Tool=1 may help to
reveal some inefficiencies in the GC.

[dvyukov, 2013-05-31 07:31:50]

Is it possible to build an svg graph similar to what pprof generates for
cpu/heap profile from the info in the log? It would be a great representation.

Type name for each block is very useful, pointer values does not provide a lot
of info.

Also I find it useful to show at what offset object A contains a pointer to
object B. E.g. runtime.M is about 10K in size, it's difficult to figure out
where exactly it contains a pointer to some object.

Also I find it useful to show allocation stacks for each object. E.g. a string
of size 16 can be allocated in any place of a program. Allocation stacks provide
a good identity.

Also I think it's important to show duplicate edges. E.g. if we reach object X
through objects A and B, we need to show both edges. But also it's important to
emphasize the edge that we actually used to scan object X, because edges from A
and B can have different type info associated with them.

[atom, 2013-05-31 09:48:14]

On 2013/05/31 07:31:50, dvyukov wrote:
> Is it possible to build an svg graph similar to what pprof generates for
> cpu/heap profile from the info in the log? It would be a great representation.

In my opinion it is questionable whether graph visualization can improve
understanding of the graph.

> Type name for each block is very useful, pointer values does not provide a lot
> of info.

This seems possible. I will take a look at the code.

> Also I find it useful to show at what offset object A contains a pointer to
> object B. E.g. runtime.M is about 10K in size, it's difficult to figure out
> where exactly it contains a pointer to some object.

I agree that showing the offsets would be useful.

> Also I find it useful to show allocation stacks for each object. E.g. a string
> of size 16 can be allocated in any place of a program. Allocation stacks
provide
> a good identity.

There seems to be no need for such information right now. I would need to see an
example which shows the use of the stack traces.

> Also I think it's important to show duplicate edges. E.g. if we reach object X
> through objects A and B, we need to show both edges. But also it's important
to
> emphasize the edge that we actually used to scan object X, because edges from
A
> and B can have different type info associated with them.

I agree.

[rsc, 2013-05-31 11:37:58]

Carl, how does this fit with what you were thinking for dumping gc
debugging information? Is there a standard format we should be using?

Russ

[cshapiro1, 2013-05-31 23:33:24]

On Fri, May 31, 2013 at 4:37 AM, Russ Cox <rsc@golang.org> wrote:

> Carl, how does this fit with what you were thinking for dumping gc
> debugging information? Is there a standard format we should be using?
>

This is different.

What I am planning to provide is a tool that dumps information about the
root set and the pointers in objects.  A user or garbage collection
developer will invoke the tool through a function call or signal delivery.
 The execution of the tool is explicitly not be tied to a garbage
collection which I believe is a critical feature.  The heap information
would be written in HPROF (with adjustments for Go) or a similar format.
 Third party tools would be used to browse the heap content and present
connectivity information and identify possible leaks.  This would be useful
for end users and developers.

This tool requires a compile time variable to be set.  Its execution is
tied to the garbage collector.  The data is written in a text file and
there is program that can compute paths to the root.   I think this could
be useful for a developer for debugging a limited set of problems.  I am
not sure if this is generally useful because it requires re-compiling and
afterward is always on.

I am also concerned about adding this code on top of the existing marking
code.