|
| 1 | +# Test & Benchmark Profiler |
| 2 | + |
| 3 | +Automatic hierarchical call tracing and performance profiling for Go tests and benchmarks in the Token SDK. |
| 4 | + |
| 5 | +## Quick Start |
| 6 | + |
| 7 | +```bash |
| 8 | +cd tools/profiler |
| 9 | +./profile.sh BenchmarkValidatorTransfer |
| 10 | +``` |
| 11 | + |
| 12 | +## What It Does |
| 13 | + |
| 14 | +1. Copies your repo to `/tmp/profiler-<PID>` (your files are never touched) |
| 15 | +2. Finds your test/benchmark in `token/` directory |
| 16 | +3. Instruments all Go packages in `token/` |
| 17 | +4. Runs with profiling |
| 18 | +5. Saves results to current directory |
| 19 | +6. Cleans up automatically |
| 20 | + |
| 21 | +**Safety:** All work happens in `/tmp`. Your repository is never modified. |
| 22 | + |
| 23 | +## Example Output |
| 24 | + |
| 25 | +``` |
| 26 | +## Call Hierarchy |
| 27 | +
|
| 28 | +└── >>> (*Validator).VerifyTransfer [2.5s, 100.00%] |
| 29 | + ├── >>> (*Validator).verifyInputs [1.8s, 72.00%] |
| 30 | + │ └── >>> (*Verifier).Verify x5 [1.5s, 60.00%] |
| 31 | + └── (*Validator).verifyOutputs [0.7s, 28.00%] |
| 32 | +
|
| 33 | +## Top 20 Functions by Time |
| 34 | +
|
| 35 | +*Note: These functions are marked with `>>>` in the call tree above* |
| 36 | +
|
| 37 | +| Function | Total Time | % of Root | |
| 38 | +|----------|------------|-----------| |
| 39 | +| (*Validator).VerifyTransfer | 2.5s | 100.00% | |
| 40 | +| (*Validator).verifyInputs | 1.8s | 72.00% | |
| 41 | +| (*Verifier).Verify | 1.5s | 60.00% | |
| 42 | +``` |
| 43 | + |
| 44 | +**Reading the output:** |
| 45 | +- `>>>` marks the top 20 functions by time |
| 46 | +- Times are **cumulative** (include all child functions) |
| 47 | +- `x5` means called 5 times (total time shown) |
| 48 | +- Percentages relative to root function |
| 49 | + |
| 50 | +## Options |
| 51 | + |
| 52 | +```bash |
| 53 | +./profile.sh <test_or_benchmark_name> [options] |
| 54 | + |
| 55 | +Options: |
| 56 | + -d, --display <mode> Display: both, time, percent (default: both) |
| 57 | + -f, --root-function <name> Start from this function (show subtree) |
| 58 | + -m, --min-percent <n> Hide functions below this % (default: 0) |
| 59 | + -h, --help Show help |
| 60 | +``` |
| 61 | + |
| 62 | +**Examples:** |
| 63 | +```bash |
| 64 | +# Show only percentages |
| 65 | +./profile.sh BenchmarkValidatorTransfer -d percent |
| 66 | + |
| 67 | +# Profile a subtree |
| 68 | +./profile.sh BenchmarkValidatorTransfer -f VerifyTransfer |
| 69 | + |
| 70 | +# Hide functions using less than 1% |
| 71 | +./profile.sh BenchmarkValidatorTransfer -m 1.0 |
| 72 | + |
| 73 | +# Profile a test |
| 74 | +./profile.sh TestValidatorTransfer |
| 75 | +``` |
| 76 | + |
| 77 | +## Scope |
| 78 | + |
| 79 | +**Searches for tests/benchmarks in:** |
| 80 | +- `token/` directory and all subdirectories |
| 81 | + |
| 82 | +**Instruments:** |
| 83 | +- All Go packages in `token/` directory |
| 84 | + |
| 85 | +**Output:** |
| 86 | +- Saved to current directory as `<TestName>_profile.md` |
| 87 | + |
| 88 | +## Manual Instrumentation |
| 89 | + |
| 90 | +The `profile.sh` script automatically instruments your code. However, you can also manually instrument code for profiling. |
| 91 | + |
| 92 | +### In Benchmarks |
| 93 | + |
| 94 | +```go |
| 95 | +import "github.com/hyperledger-labs/fabric-token-sdk/tools/profiler/tracer" |
| 96 | + |
| 97 | +func BenchmarkValidatorTransfer(b *testing.B) { |
| 98 | + // Enable tracer |
| 99 | + tracer.Enable() |
| 100 | + defer tracer.Disable() |
| 101 | + |
| 102 | + // Setup code (not profiled) |
| 103 | + validator := setupValidator() |
| 104 | + request := generateRequest() |
| 105 | + |
| 106 | + b.ResetTimer() |
| 107 | + for i := 0; i < b.N; i++ { |
| 108 | + // This will be profiled if functions have tracer.Enter() calls |
| 109 | + err := validator.VerifyTransfer(request) |
| 110 | + if err != nil { |
| 111 | + b.Fatal(err) |
| 112 | + } |
| 113 | + } |
| 114 | + b.StopTimer() |
| 115 | + |
| 116 | + // Print profile |
| 117 | + tracer.PrintWithOptions(tracer.PrintOptions{ |
| 118 | + RootFunction: "VerifyTransfer", |
| 119 | + ShowPercent: true, |
| 120 | + ShowAbsolute: true, |
| 121 | + AggregateLoops: true, |
| 122 | + }) |
| 123 | +} |
| 124 | + |
| 125 | +// Each function you want to profile needs this: |
| 126 | +func (v *Validator) VerifyTransfer(req *Request) error { |
| 127 | + defer tracer.Enter("(*Validator).VerifyTransfer")() |
| 128 | + // ... function body ... |
| 129 | +} |
| 130 | +``` |
| 131 | + |
| 132 | +### In Tests |
| 133 | + |
| 134 | +```go |
| 135 | +func TestValidatorTransfer(t *testing.T) { |
| 136 | + // Enable tracer |
| 137 | + tracer.Enable() |
| 138 | + defer tracer.Disable() |
| 139 | + |
| 140 | + // Run test |
| 141 | + validator := setupValidator() |
| 142 | + request := generateRequest() |
| 143 | + |
| 144 | + err := validator.VerifyTransfer(request) |
| 145 | + require.NoError(t, err) |
| 146 | + |
| 147 | + // Print profile |
| 148 | + tracer.PrintWithOptions(tracer.PrintOptions{ |
| 149 | + RootFunction: "VerifyTransfer", |
| 150 | + ShowPercent: true, |
| 151 | + ShowAbsolute: true, |
| 152 | + AggregateLoops: true, |
| 153 | + }) |
| 154 | +} |
| 155 | +``` |
| 156 | + |
| 157 | +**Note:** Manual instrumentation requires adding `defer tracer.Enter("FunctionName")()` to every function you want to profile. The `profile.sh` script does this automatically by: |
| 158 | +1. Copying your code to a temporary directory |
| 159 | +2. Running `auto-instrument.go` to add tracer calls |
| 160 | +3. Running the test/benchmark |
| 161 | +4. Cleaning up |
| 162 | + |
| 163 | +For most use cases, use `profile.sh` instead of manual instrumentation. |
| 164 | + |
| 165 | +## Files |
| 166 | + |
| 167 | +- `profile.sh` - Automated profiling script |
| 168 | +- `auto-instrument.go` - Adds tracer hooks to Go files |
| 169 | +- `inject-tracer.go` - Injects tracer into test/benchmark |
| 170 | +- `tracer/` - Runtime tracing library |
| 171 | + |
| 172 | +## Troubleshooting |
| 173 | + |
| 174 | +**Can't find test/benchmark:** |
| 175 | +- Check spelling |
| 176 | +- Ensure it's in `token/` directory |
| 177 | + |
| 178 | +**Empty output file:** |
| 179 | +- Check if test/benchmark runs successfully |
| 180 | +- Look for compilation errors in script output |
| 181 | + |
| 182 | +**Times don't add up:** |
| 183 | +- Times are cumulative (include children) |
| 184 | +- Use percentages to see relative contributions |
0 commit comments