feat(cli): 1D: PPROF extensions: Start and Stop profiling functions

[aaron-kasten]

This is a continuation of #3454

This is one of 8 PRs in a PR train:
aaron-kasten/kopia:pprof-extensions-c-1a
aaron-kasten/kopia:pprof-extensions-c-1b
aaron-kasten/kopia:pprof-extensions-c-1c
aaron-kasten/kopia:pprof-extensions-c-1d
aaron-kasten/kopia:pprof-extensions-c-1e
aaron-kasten/kopia:pprof-extensions-c-1f
aaron-kasten/kopia:pprof-extensions-c-1g

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 #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

[codecov]

Codecov Report

Attention: Patch coverage is 75.52448% with 35 lines in your changes are missing coverage. Please review.

Project coverage is 77.09%. Comparing base (cb455c6) to head (9bf6715).
Report is 56 commits behind head on master.

❗ Current head 9bf6715 differs from pull request most recent head 1e7666b. Consider uploading reports for the commit 1e7666b to get more accurate results

Files	Patch %	Lines
internal/pproflogging/pproflogging.go	75.52%	22 Missing and 13 partials ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #3674      +/-   ##
==========================================
+ Coverage   75.86%   77.09%   +1.22%     
==========================================
  Files         470      471       +1     
  Lines       37301    28713    -8588     
==========================================
- Hits        28299    22135    -6164     
+ Misses       7071     4641    -2430     
- Partials     1931     1937       +6     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.