rkt: Add `--cpuprofile` `--memprofile` for profiling the rkt #2887

yifan-gu · 2016-07-07T21:32:14Z

Add two hidden global flags to enable profiling rkt.
Also add documentation about how to build and use the flags.

s-urbaniak · 2016-07-08T08:40:25Z

rkt/profile_stub.go

+func parseProfileFlags(cmdRkt *cobra.Command) {}
+
+func startProfile() (cpufile *os.File, memfile *os.File, err error) {
+	return nil, nil, nil


I suggest to write out a log entry for the user as a hint, that profiling was disabled at compile time.

OK, maybe in the debugging mode.

jonboulle · 2016-07-08T10:10:02Z

Why do we need to hide this behind a build flag - wouldn't a runtime flag be enough?

yifan-gu · 2016-07-08T18:31:00Z

@jonboulle I think this should be a development feature, general users normally should not bother profiling rkt. Instead, they should be able to benchmark rkt though, which we already provided some facilities.
Given that, I'd like to hide the flags to reduce flag noises.

yifan-gu · 2016-07-08T18:35:40Z

@jonboulle But on the other side, the benefit of enabling the profiling flag unconditionally is that when a user reports some "high cpu usage" issue, we can ask them to provide the profiling result easily without rebuilding the rkt.

euank · 2016-07-08T22:45:37Z

If it is a runtime flag, we could also make it a hidden flag that can only be found via developer documentation if that's a concern.

Reasons for build-flag:

slightly smaller executable for users
allows it to be printed for dev builds / shown as a configure flag (possibly preferable to hidden or runtime)
paves the way for further profile gated things, like structured logging or call analysis etc, some of which could have stronger reasons to not compile in normally (e.g. performance hit)

Reasons for runtime flag:

Easier to ask users to provide dumps / information from this
Easier for developers to not have to deal with build flags and
Slightly less autotools 🔥

I'm indifferent overall on which we go with though.

yifan-gu · 2016-07-08T23:05:32Z

@euank I don't know we can do hidden flags, that one sounds like a middle ground.

jonboulle · 2016-07-11T15:35:59Z

@alban view?

alban · 2016-07-12T10:37:39Z

@jonboulle I prefer a runtime flag for simplicity, but it's not a strong preference.

The profiling code does not seem to include any new dependencies that would be difficult to package in Debian, so a runtime flag should not be a problem.

lucab · 2016-07-12T14:31:42Z

@yifan-gu #2868 has landed so you can rebase on top of it. I also agree with above reviewers that an hidden CLI should be enough at this point, given the small amount of additional code.

jonboulle · 2016-07-12T14:32:22Z

IMHO let's go with a hidden flag

yifan-gu · 2016-07-13T01:30:01Z

Updated the PR to use hidden flags.

alban · 2016-07-13T10:08:29Z

The hidden flags are documented in Documentation/commands.md with the other global options. Should they be in a separate table instead? /cc @joshix

alban · 2016-07-13T10:11:04Z

rkt/rkt.go

 // runWrapper returns a func(cmd *cobra.Command, args []string) that internally
 // will add command function return code and the reinsertion of the "--" flag
 // terminator.
 func runWrapper(cf func(cmd *cobra.Command, args []string) (exit int)) func(cmd *cobra.Command, args []string) {
 	return func(cmd *cobra.Command, args []string) {
+		cpufile, memfile, err := startProfile()
+		if err != nil {
+			stderr.Printf("cannot setup profiling %v", err)


Could this use stderr.PrintE() to be consistent with the rest? Or is it too early and --debug isn't parsed yet?

If stderr.PrintE() cannot be used, there should be a : before the %v.

Replaced with stderr.PrintE

yifan-gu · 2016-07-13T18:00:52Z

The hidden flags are documented in Documentation/commands.md with the other global options. Should they be in a separate table instead? /cc @joshix

I added a hint saying this is a hidden flag. Open to suggestions.
Maybe remove them at all and only mention in the profiling documentation?

euank · 2016-07-13T18:30:42Z

rkt/rkt.go

+}
+
+func stopProfile(cpuprofile, memprofile *os.File) {
+	pprof.StopCPUProfile()


wrap in either nil or flag checks in case they weren't enabled? I think WriteHeapProfile might do work whenever it's called, so we should avoid calling it if it's not enabled.

@euank good catch, thanks.

iaguis · 2016-07-18T13:52:48Z

Documentation/performance/README.md

+
+```shell
+$ sudo /usr/bin/rkt --cpuprofile=/tmp/cpu.profile --memprofile=/tmp/mem.profile gc --grace-period=0
+$ go tools pprof /usr/bin/rkt /tmp/cpu.profile


s/tools/tool/

iaguis · 2016-07-18T13:53:16Z

One nit but LGTM after that.

yifan-gu · 2016-07-18T18:22:23Z

Fixed the typos.

These are hidden flags, so users will not find them in the help.

yifan-gu · 2016-07-18T20:08:43Z

19:02:44 === RUN   TestNetDefaultRestrictedConnectivity
19:02:51 --- FAIL: TestNetDefaultRestrictedConnectivity (6.69s)
19:02:51    rkt_tests.go:115: Running command: /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/tmp/functional/rkt --dir=/tmp/datadir-255390103 --local-config=/tmp/localdir-290079242 --system-config=/tmp/systemdir-688845793 --user-config=/tmp/userdir-616822732 --debug --insecure-options=image run --net=default-restricted --mds-register=false /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/tmp/functional/test-tmp/rkt-inspect-networking.aci
19:02:51    goroutineassistant.go:64: Error encountered - shutting down
19:02:51    goroutineassistant.go:65: Get http://172.16.28.2:49152: dial tcp 172.16.28.2:49152: getsockopt: connection refused
19:02:51        
19:02:51 panic: Failed to remove temporary data directory "/tmp/datadir-255390103": remove /tmp/datadir-255390103/pods/run/17421b97-926e-4b25-be37-4cecf1fb0bc1/stage1/rootfs/sys: device or resource busy [recovered]
19:02:51    panic: Failed to remove temporary data directory "/tmp/datadir-255390103": remove /tmp/datadir-255390103/pods/run/17421b97-926e-4b25-be37-4cecf1fb0bc1/stage1/rootfs/sys: device or resource busy
19:02:51 
19:02:51 goroutine 481 [running]:
19:02:51 panic(0xa3b480, 0xc8203954b0)
19:02:51    /usr/lib/go-1.6/src/runtime/panic.go:481 +0x3e6
19:02:51 testing.tRunner.func1(0xc8204126c0)
19:02:51    /usr/lib/go-1.6/src/testing/testing.go:467 +0x192
19:02:51 panic(0xa3b480, 0xc8203954b0)
19:02:51    /usr/lib/go-1.6/src/runtime/panic.go:443 +0x4e9
19:02:51 github.com/coreos/rkt/tests/testutils.(*dirDesc).cleanup(0xc8202491c0)
19:02:51    /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/gopath/src/github.com/coreos/rkt/tests/testutils/ctx.go:67 +0x27c
19:02:51 github.com/coreos/rkt/tests/testutils.(*RktRunCtx).Cleanup(0xc8202492c0)
19:02:51    /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/gopath/src/github.com/coreos/rkt/tests/testutils/ctx.go:173 +0x1be
19:02:51 runtime.Goexit()
19:02:51    /usr/lib/go-1.6/src/runtime/panic.go:340 +0xfb
19:02:51 testing.(*common).FailNow(0xc8204126c0)
19:02:51    /usr/lib/go-1.6/src/testing/testing.go:346 +0x36
19:02:51 testing.(*common).Fatal(0xc8204126c0, 0xc820209c28, 0x1, 0x1)
19:02:51    /usr/lib/go-1.6/src/testing/testing.go:383 +0x6f
19:02:51 github.com/coreos/rkt/tests/testutils.(*GoroutineAssistant).Wait(0xc8203e0d20)
19:02:51    /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/gopath/src/github.com/coreos/rkt/tests/testutils/goroutineassistant.go:65 +0x195
19:02:51 github.com/coreos/rkt/tests.NewTestNetDefaultRestrictedConnectivity.func1.1(0xce9de0, 0x18)
19:02:51    /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/gopath/src/github.com/coreos/rkt/tests/rkt_net_test.go:353 +0xbf0
19:02:51 github.com/coreos/rkt/tests.NewTestNetDefaultRestrictedConnectivity.func1(0xc8204126c0)
19:02:51    /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/gopath/src/github.com/coreos/rkt/tests/rkt_net_test.go:355 +0x92
19:02:51 github.com/coreos/rkt/tests/testutils.TestFunc.Execute(0xdb47f0, 0xc8204126c0)
19:02:51    /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/gopath/src/github.com/coreos/rkt/tests/testutils/test.go:31 +0x26
19:02:51 github.com/coreos/rkt/tests.TestNetDefaultRestrictedConnectivity(0xc8204126c0)
19:02:51    /home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/gopath/src/github.com/coreos/rkt/tests/rkt_net_nspawn_test.go:76 +0x3f
19:02:51 testing.tRunner(0xc8204126c0, 0x1238550)
19:02:51    /usr/lib/go-1.6/src/testing/testing.go:473 +0x98
19:02:51 created by testing.RunTests
19:02:51    /usr/lib/go-1.6/src/testing/testing.go:582 +0x892
19:02:51 exit status 2
19:02:51 FAIL   github.com/coreos/rkt/tests 1199.008s
19:02:51 tests/functional.mk:82: recipe for target '/home/admin/workspace/rkt-github-ci/os_type/debian-8/stage1_flavor/coreos/builds/build-rkt-coreos/build-rkt-1.10.0+git/stamps/__tests_functional_mk_functional_tests.stamp' failed

cc @steveej

iaguis · 2016-07-19T16:15:25Z

LGTM and tests failures are not related

yifan-gu added area/developer tooling area/performance labels Jul 7, 2016

yifan-gu added this to the v1.11.0 milestone Jul 7, 2016

s-urbaniak reviewed Jul 8, 2016
View reviewed changes

lucab added the needs/rebase label Jul 12, 2016

yifan-gu changed the title ~~rkt: Add --enable-profile build options~~ rkt: Add --cpuprofile --memprofile for profiling the rkt Jul 13, 2016

yifan-gu force-pushed the profile branch 2 times, most recently from b9ee190 to 5ce9960 Compare July 13, 2016 01:09

yifan-gu added needs/review and removed needs/rebase labels Jul 13, 2016

yifan-gu force-pushed the profile branch from 5ce9960 to 0b60002 Compare July 13, 2016 01:11

alban reviewed Jul 13, 2016
View reviewed changes

yifan-gu force-pushed the profile branch from 0b60002 to 17165cc Compare July 13, 2016 17:59

euank reviewed Jul 13, 2016
View reviewed changes

yifan-gu force-pushed the profile branch from 17165cc to 286761c Compare July 14, 2016 16:36

iaguis reviewed Jul 18, 2016
View reviewed changes

yifan-gu force-pushed the profile branch from 286761c to 4205dae Compare July 18, 2016 18:22

Yifan Gu added 2 commits July 18, 2016 11:36

rkt: Add --cpuprofile and --memprofile to enable profiling rkt.

6b738be

These are hidden flags, so users will not find them in the help.

Documentation: Add documentation about profiling.

6a9ef42

yifan-gu force-pushed the profile branch from 4205dae to 6a9ef42 Compare July 18, 2016 18:36

yifan-gu mentioned this pull request Jul 18, 2016

Test TestNetDefaultRestrictedConnectivity fails #2943

Closed

iaguis added reviewed/lgtm and removed needs/review labels Jul 19, 2016

iaguis merged commit e61deb2 into rkt:master Jul 19, 2016

yifan-gu deleted the profile branch July 20, 2016 16:03

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

rkt: Add `--cpuprofile` `--memprofile` for profiling the rkt #2887

rkt: Add `--cpuprofile` `--memprofile` for profiling the rkt #2887

yifan-gu commented Jul 7, 2016 •

edited

Loading

s-urbaniak Jul 8, 2016

yifan-gu Jul 8, 2016

jonboulle commented Jul 8, 2016

yifan-gu commented Jul 8, 2016 •

edited

Loading

yifan-gu commented Jul 8, 2016 •

edited

Loading

euank commented Jul 8, 2016

yifan-gu commented Jul 8, 2016

jonboulle commented Jul 11, 2016

alban commented Jul 12, 2016

lucab commented Jul 12, 2016

jonboulle commented Jul 12, 2016

yifan-gu commented Jul 13, 2016

alban commented Jul 13, 2016

alban Jul 13, 2016

yifan-gu Jul 13, 2016

yifan-gu commented Jul 13, 2016

euank Jul 13, 2016

yifan-gu Jul 14, 2016

iaguis Jul 18, 2016

iaguis commented Jul 18, 2016

yifan-gu commented Jul 18, 2016

yifan-gu commented Jul 18, 2016

iaguis commented Jul 19, 2016

rkt: Add --cpuprofile --memprofile for profiling the rkt #2887

rkt: Add --cpuprofile --memprofile for profiling the rkt #2887

Conversation

yifan-gu commented Jul 7, 2016 • edited Loading

s-urbaniak Jul 8, 2016

Choose a reason for hiding this comment

yifan-gu Jul 8, 2016

Choose a reason for hiding this comment

jonboulle commented Jul 8, 2016

yifan-gu commented Jul 8, 2016 • edited Loading

yifan-gu commented Jul 8, 2016 • edited Loading

euank commented Jul 8, 2016

yifan-gu commented Jul 8, 2016

jonboulle commented Jul 11, 2016

alban commented Jul 12, 2016

lucab commented Jul 12, 2016

jonboulle commented Jul 12, 2016

yifan-gu commented Jul 13, 2016

alban commented Jul 13, 2016

alban Jul 13, 2016

Choose a reason for hiding this comment

yifan-gu Jul 13, 2016

Choose a reason for hiding this comment

yifan-gu commented Jul 13, 2016

euank Jul 13, 2016

Choose a reason for hiding this comment

yifan-gu Jul 14, 2016

Choose a reason for hiding this comment

iaguis Jul 18, 2016

Choose a reason for hiding this comment

iaguis commented Jul 18, 2016

yifan-gu commented Jul 18, 2016

yifan-gu commented Jul 18, 2016

iaguis commented Jul 19, 2016

rkt: Add `--cpuprofile` `--memprofile` for profiling the rkt #2887

rkt: Add `--cpuprofile` `--memprofile` for profiling the rkt #2887

yifan-gu commented Jul 7, 2016 •

edited

Loading

yifan-gu commented Jul 8, 2016 •

edited

Loading

yifan-gu commented Jul 8, 2016 •

edited

Loading