|
| 1 | +# Profiling the Drift Python SDK |
| 2 | + |
| 3 | +This document explains how to profile the SDK to understand where performance overhead comes from. |
| 4 | + |
| 5 | +## Quick Start |
| 6 | + |
| 7 | +```bash |
| 8 | +cd /path/to/drift-python-sdk |
| 9 | + |
| 10 | +# Run cProfile (recommended starting point) |
| 11 | +./benchmarks/profile/profile.sh cprofile |
| 12 | +``` |
| 13 | + |
| 14 | +## Available Profilers |
| 15 | + |
| 16 | +### 1. cProfile (Built-in, Deterministic) |
| 17 | + |
| 18 | +**Best for:** Understanding call counts and cumulative time per function. |
| 19 | + |
| 20 | +```bash |
| 21 | +./benchmarks/profile/profile.sh cprofile |
| 22 | +``` |
| 23 | + |
| 24 | +This runs the profiling workload and outputs: |
| 25 | + |
| 26 | +- A `.prof` file in `benchmarks/profile/results/` |
| 27 | +- Summary of top functions by cumulative and total time |
| 28 | + |
| 29 | +**View interactively with snakeviz:** |
| 30 | + |
| 31 | +```bash |
| 32 | +pip install snakeviz |
| 33 | +snakeviz benchmarks/profile/results/cprofile_*.prof |
| 34 | +``` |
| 35 | + |
| 36 | +Opens an interactive sunburst diagram in your browser showing the call hierarchy. |
| 37 | + |
| 38 | +### 2. py-spy (Sampling, Flame Graphs) |
| 39 | + |
| 40 | +**Best for:** Low-overhead profiling and classic flame graph visualization. |
| 41 | + |
| 42 | +```bash |
| 43 | +# Requires sudo on macOS |
| 44 | +sudo ./benchmarks/profile/profile.sh pyspy |
| 45 | +``` |
| 46 | + |
| 47 | +Generates an SVG flame graph that you can open in any browser. |
| 48 | + |
| 49 | +**Install:** |
| 50 | + |
| 51 | +```bash |
| 52 | +pip install py-spy |
| 53 | +# Or on macOS: brew install py-spy |
| 54 | +``` |
| 55 | + |
| 56 | +### 3. Scalene (CPU + Memory) |
| 57 | + |
| 58 | +**Best for:** Understanding both CPU time and memory allocation per line. |
| 59 | + |
| 60 | +```bash |
| 61 | +pip install scalene |
| 62 | +./benchmarks/profile/profile.sh scalene |
| 63 | +``` |
| 64 | + |
| 65 | +Generates an HTML report with line-by-line CPU and memory breakdown. |
| 66 | + |
| 67 | +### 4. VizTracer (Timeline) |
| 68 | + |
| 69 | +**Best for:** Seeing the sequence and timing of function calls over time. |
| 70 | + |
| 71 | +```bash |
| 72 | +pip install viztracer |
| 73 | +./benchmarks/profile/profile.sh viztracer |
| 74 | +``` |
| 75 | + |
| 76 | +**View the trace:** |
| 77 | + |
| 78 | +```bash |
| 79 | +vizviewer benchmarks/profile/results/viztracer_*.json |
| 80 | +``` |
| 81 | + |
| 82 | +Opens a Chrome DevTools-style timeline visualization. |
| 83 | + |
| 84 | +## Profile Analysis Results |
| 85 | + |
| 86 | +Based on profiling 500 HTTP requests through the SDK: |
| 87 | + |
| 88 | +### Top Overhead Sources |
| 89 | + |
| 90 | +| Function | Time/Call | Description | |
| 91 | +|----------|-----------|-------------| |
| 92 | +| `span_serialization.clean_span_to_proto` | ~1.7ms | Converting spans to protobuf format | |
| 93 | +| `td_span_processor.on_end` | ~2.1ms | Processing spans when they complete | |
| 94 | +| `handler.finalize_wsgi_span` | ~2.2ms | Finalizing HTTP/WSGI spans | |
| 95 | +| `otel_converter.otel_span_to_clean_span_data` | ~0.4ms | Converting OpenTelemetry spans | |
| 96 | + |
| 97 | +### Key Findings |
| 98 | + |
| 99 | +1. **Span serialization is the biggest bottleneck** |
| 100 | + - `_dict_to_struct`, `_value_to_proto`, `_json_schema_to_proto` are called recursively |
| 101 | + - Converting rich span data to protobuf is inherently expensive |
| 102 | + |
| 103 | +2. **The instrumentation itself is cheap** |
| 104 | + - Function patching/wrapping adds minimal overhead |
| 105 | + - Most time is spent in span processing, not in the hooks |
| 106 | + |
| 107 | +3. **Sampling reduces overhead proportionally** |
| 108 | + - At 10% sampling, most requests skip span serialization entirely |
| 109 | + - This explains why lower sampling rates dramatically improve performance |
| 110 | + |
| 111 | +### Optimization Opportunities |
| 112 | + |
| 113 | +Based on the profile data: |
| 114 | + |
| 115 | +1. Lazy serialization - Defer protobuf conversion until export time |
| 116 | +2. Batch serialization - Serialize multiple spans together |
| 117 | +3. Schema caching - Cache JSON schema conversions |
| 118 | +4. Attribute filtering - Skip serializing large/unnecessary attributes |
| 119 | + |
| 120 | +## Custom Profiling |
| 121 | + |
| 122 | +### Profile a Specific Workload |
| 123 | + |
| 124 | +Edit `benchmarks/profile/simple_profile.py` to customize: |
| 125 | + |
| 126 | +```python |
| 127 | +# Adjust number of iterations |
| 128 | +iterations = 1000 |
| 129 | + |
| 130 | +# Change request mix |
| 131 | +if i % 3 == 0: |
| 132 | + # Your custom endpoint |
| 133 | + response = session.get(f"{server_url}/your-endpoint") |
| 134 | +``` |
| 135 | + |
| 136 | +### Profile with Different SDK Settings |
| 137 | + |
| 138 | +```python |
| 139 | +# In simple_profile.py, modify SDK initialization: |
| 140 | +sdk = TuskDrift.initialize( |
| 141 | + api_key="profile-test-key", |
| 142 | + env="profile", |
| 143 | + sampling_rate=0.1, # Test with different sampling rates |
| 144 | + transforms={...}, # Test with transforms enabled |
| 145 | + log_level="warning", |
| 146 | +) |
| 147 | +``` |
| 148 | + |
| 149 | +### Profile Production Code |
| 150 | + |
| 151 | +You can use py-spy to attach to a running process: |
| 152 | + |
| 153 | +```bash |
| 154 | +# Find your Python process PID |
| 155 | +ps aux | grep python |
| 156 | + |
| 157 | +# Attach and record |
| 158 | +sudo py-spy record -o profile.svg --pid <PID> --duration 30 |
| 159 | +``` |
| 160 | + |
| 161 | +## Comparing Before/After Changes |
| 162 | + |
| 163 | +1. Run profile before changes: |
| 164 | + |
| 165 | + ```bash |
| 166 | + ./benchmarks/profile/profile.sh cprofile |
| 167 | + mv benchmarks/profile/results/cprofile_*.prof benchmarks/profile/results/before.prof |
| 168 | + ``` |
| 169 | + |
| 170 | +2. Make your changes |
| 171 | + |
| 172 | +3. Run profile after changes: |
| 173 | + |
| 174 | + ```bash |
| 175 | + ./benchmarks/profile/profile.sh cprofile |
| 176 | + mv benchmarks/profile/results/cprofile_*.prof benchmarks/profile/results/after.prof |
| 177 | + ``` |
| 178 | + |
| 179 | +4. Compare with pstats: |
| 180 | + |
| 181 | + ```python |
| 182 | + import pstats |
| 183 | + |
| 184 | + before = pstats.Stats('benchmarks/profile/results/before.prof') |
| 185 | + after = pstats.Stats('benchmarks/profile/results/after.prof') |
| 186 | + |
| 187 | + print("=== BEFORE ===") |
| 188 | + before.strip_dirs().sort_stats('cumulative').print_stats(20) |
| 189 | + |
| 190 | + print("=== AFTER ===") |
| 191 | + after.strip_dirs().sort_stats('cumulative').print_stats(20) |
| 192 | + ``` |
| 193 | + |
| 194 | +## Output Files |
| 195 | + |
| 196 | +Profile results are saved to `benchmarks/profile/results/` (gitignored): |
| 197 | + |
| 198 | +| File | Description | |
| 199 | +|------|-------------| |
| 200 | +| `cprofile_*.prof` | cProfile binary data | |
| 201 | +| `flamegraph_*.svg` | py-spy flame graph | |
| 202 | +| `scalene_*.html` | Scalene HTML report | |
| 203 | +| `viztracer_*.json` | VizTracer timeline data | |
| 204 | +| `traces/` | SDK trace output during profiling | |
| 205 | + |
| 206 | +## Tips |
| 207 | + |
| 208 | +- **Start with cProfile** - It's built-in and gives good overview |
| 209 | +- **Use snakeviz for exploration** - Interactive visualization helps find hotspots |
| 210 | +- **Profile realistic workloads** - Micro-benchmarks may not reflect production patterns |
| 211 | +- **Compare sampling rates** - Profile with 100% vs 10% sampling to see the difference |
| 212 | +- **Watch for I/O** - File writes and network calls can dominate profiles |
0 commit comments