feat(cli): c2: PPROF extensions

[aaron-kasten]

This PR adds the ability to dump pprof data to logs for debugging.

This is a continuation of kopia#3454

This is one of 8 PRs in a PR train:
aaron-kasten/kopia:pprof-extensions-c1a
aaron-kasten/kopia:pprof-extensions-c1b
aaron-kasten/kopia:pprof-extensions-c2
aaron-kasten/kopia:pprof-extensions-c3
aaron-kasten/kopia:pprof-extensions-c4
aaron-kasten/kopia:pprof-extensions-c5
aaron-kasten/kopia:pprof-extensions-c6
aaron-kasten/kopia:pprof-extensions-c7

Usage

pprof dumps are configured using the KOPIA_DEBUG_PPROF environment variable. The variable is a list of pprof profile names (see pprof.Lookup) separated by ,. Optional parameters can be set with '=', delimited by ':'.

example:

export KOPIA_DEBUG_PPROF=cpu,heap=debug=1,mutex=debug=1:rate=1000

The above setting will produce CPU, heap and mutex profiles. The block profile will have its debug parameter set to 1 and its sample rate set to 1000

Once run, profile data will be output in the Kopia logs on termination. Profile dumps are generated as base64 output (PEM) to the log on termination.

You should consider captureing logs to a file when running the Kopia command:

$ kopia --log-file ./myout.log snapshot create . &
[1] 77308

Once the logs are captured, a dump can created by terminating the command:

$ kill %1

The following signals (on Linux and macos) can be used to dump profiles: SIGTERM, SIGINT, and SIGUSR1.

Captured standard-output should look similar to:

saving PEM buffers for output
2021/11/16 19:38:59 Shutting down...
dumping PEM for "PPROF MEM"
-----BEGIN PPROF MEM-----
H4sIAAAAAAAE/7R8CXxURfIw3ZOEJkTTGUUK8Hg8FZMoM8kDBHTXlUtFPBDwWteN
w+RlGJnMG2cmIO7uf4PcN8qtcsqNXCIgghgQBMUL8RYVFPHAAw/UVdTvV9VvzswE
.
.
.
sOBRWRMwE4RCnvDAimrjlBhatdcTCGSqZ9kAbk+k2i4YRBLMVXsCvgQzQXNwKGzh
l3HYSLE3drEgweOQCN7Jjnq8A43CtKt5Rt5tgyoj1u1G/m2DIkMiXk8gcPv/CwAA
//8psEjOrZ4AAA==
-----END PPROF MEM-----

The captured output can then be converted to a pprof binary by using kats. The Kopia kats tool can be used to convert the PEM file into a binary:

$ ./go/bin/kats dump.b64
writing PEM "PPROF MEM" to file "pprof_mem.bin"

When successful, kats will output the file found in the capture file.

kats expects that there is a well formed PEM record in the capture file.

 ./go/bin/kats --help
 Usage of ./go/bin/kats:
  -verbose
    	verbose outout

Once successful, the binary can be used in PPROF:

$ go tool pprof ./pprof_mem.bin
File: pprof_mem.bin
Type: inuse_space
Time: Nov 16, 2021 at 11:38am (PST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) tree
Showing nodes accounting for 35248.89kB, 100% of 35248.89kB total
Showing top 80 nodes out of 127
----------------------------------------------------------+-------------
      flat  flat%   sum%        cum   cum%   calls calls% + context
----------------------------------------------------------+-------------
   16384kB 46.48% 46.48%    16384kB 46.48%                | kopia/tracing.StartProfileBuffers
----------------------------------------------------------+-------------
                                         2561.41kB   100% |   encoding/json.(*decodeState).object
 2561.41kB  7.27% 53.75%  2561.41kB  7.27%                | reflect.mapassign

Configuration Options

TBDThis PR adds the ability to dump pprof data to logs for debugging.

This is a continuation of kopia#3454

This is one of 4 PRs in a PR train:
aaron-kasten/kopia:pprof-extensions-A
aaron-kasten/kopia:pprof-extensions-B
aaron-kasten/kopia:pprof-extensions-C
aaron-kasten/kopia:pprof-extensions-D

Usage

pprof dumps are configured using the KOPIA_DEBUG_PPROF environment variable. The variable is a list of pprof profile names (see pprof.Lookup) separated by ,. Optional parameters can be set with '=', delimited by ':'.

example:

export KOPIA_DEBUG_PPROF=cpu,heap=debug=1,mutex=debug=1:rate=1000

The above setting will produce CPU, heap and mutex profiles. The block profile will have its debug parameter set to 1 and its sample rate set to 1000

Once run, profile data will be output in the Kopia logs on termination. Profile dumps are generated as base64 output (PEM) to the log on termination.

You should consider captureing logs to a file when running the Kopia command:

$ kopia --log-file ./myout.log snapshot create . &
[1] 77308

Once the logs are captured, a dump can created by terminating the command:

$ kill %1

The following signals (on Linux and macos) can be used to dump profiles: SIGTERM, SIGINT, and SIGUSR1.

Captured standard-output should look similar to:

saving PEM buffers for output
2021/11/16 19:38:59 Shutting down...
dumping PEM for "PPROF MEM"
-----BEGIN PPROF MEM-----
H4sIAAAAAAAE/7R8CXxURfIw3ZOEJkTTGUUK8Hg8FZMoM8kDBHTXlUtFPBDwWteN
w+RlGJnMG2cmIO7uf4PcN8qtcsqNXCIgghgQBMUL8RYVFPHAAw/UVdTvV9VvzswE
.
.
.
sOBRWRMwE4RCnvDAimrjlBhatdcTCGSqZ9kAbk+k2i4YRBLMVXsCvgQzQXNwKGzh
l3HYSLE3drEgweOQCN7Jjnq8A43CtKt5Rt5tgyoj1u1G/m2DIkMiXk8gcPv/CwAA
//8psEjOrZ4AAA==
-----END PPROF MEM-----

The captured output can then be converted to a pprof binary by using kats. The Kopia kats tool can be used to convert the PEM file into a binary:

$ ./go/bin/kats dump.b64
writing PEM "PPROF MEM" to file "pprof_mem.bin"

When successful, kats will output the file found in the capture file.

kats expects that there is a well formed PEM record in the capture file.

 ./go/bin/kats --help
 Usage of ./go/bin/kats:
  -verbose
    	verbose outout

Once successful, the binary can be used in PPROF:

$ go tool pprof ./pprof_mem.bin
File: pprof_mem.bin
Type: inuse_space
Time: Nov 16, 2021 at 11:38am (PST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) tree
Showing nodes accounting for 35248.89kB, 100% of 35248.89kB total
Showing top 80 nodes out of 127
----------------------------------------------------------+-------------
      flat  flat%   sum%        cum   cum%   calls calls% + context
----------------------------------------------------------+-------------
   16384kB 46.48% 46.48%    16384kB 46.48%                | kopia/tracing.StartProfileBuffers
----------------------------------------------------------+-------------
                                         2561.41kB   100% |   encoding/json.(*decodeState).object
 2561.41kB  7.27% 53.75%  2561.41kB  7.27%                | reflect.mapassign

Configuration Options

TBD