|
| 1 | +# Structured Logging Implementation Plan |
| 2 | + |
| 3 | +**Status**: 🟡 **Planning Phase** |
| 4 | +**Created**: September 16, 2025 |
| 5 | +**Last Updated**: September 16, 2025 |
| 6 | + |
| 7 | +## 📋 Overview |
| 8 | + |
| 9 | +This document outlines the implementation plan for introducing hierarchical structured logging using tracing spans to align with our three-level architecture (Commands → Steps → Remote Actions). |
| 10 | + |
| 11 | +### 🎯 Goals |
| 12 | + |
| 13 | +- ✅ Create hierarchical log structure that mirrors the three-level architecture |
| 14 | +- ✅ Improve debugging and monitoring capabilities |
| 15 | +- ✅ Maintain format independence (console, JSON, OpenTelemetry compatibility) |
| 16 | +- ✅ Preserve existing structured logging functionality |
| 17 | +- ✅ Enable better correlation and filtering of related log events |
| 18 | + |
| 19 | +### 🏗️ Architecture Alignment |
| 20 | + |
| 21 | +```text |
| 22 | +Level 1: Commands (Top-level orchestration) |
| 23 | +├── Level 2: Steps (Mid-level execution units) |
| 24 | +│ └── Level 3: Remote Actions (Leaf-level operations) |
| 25 | +``` |
| 26 | + |
| 27 | +## 🚀 Implementation Phases |
| 28 | + |
| 29 | +### Phase 1: Commands (Level 1) - Foundation |
| 30 | + |
| 31 | +**Status**: 🔴 **Not Started** |
| 32 | +**Priority**: High |
| 33 | +**Estimated Effort**: 2-3 days |
| 34 | + |
| 35 | +#### Tasks |
| 36 | + |
| 37 | +- [ ] **1.1** Add `#[instrument]` to `ProvisionCommand::execute()` |
| 38 | + |
| 39 | + - File: `src/commands/provision.rs` |
| 40 | + - Span name: `provision_command` |
| 41 | + - Fields: `command_type="provision"` |
| 42 | + |
| 43 | +- [ ] **1.2** Add `#[instrument]` to `ConfigureCommand::execute()` |
| 44 | + |
| 45 | + - File: `src/commands/configure.rs` |
| 46 | + - Span name: `configure_command` |
| 47 | + - Fields: `command_type="configure"` |
| 48 | + |
| 49 | +- [ ] **1.3** Add `#[instrument]` to `TestCommand::execute()` |
| 50 | + |
| 51 | + - File: `src/commands/test.rs` |
| 52 | + - Span name: `test_command` |
| 53 | + - Fields: `command_type="test"` |
| 54 | + |
| 55 | +- [ ] **1.4** Verify dependencies and features |
| 56 | + - Ensure `tracing = { features = ["attributes"] }` in `Cargo.toml` |
| 57 | + - Test span creation and nesting |
| 58 | + |
| 59 | +#### Acceptance Criteria |
| 60 | + |
| 61 | +- All command-level operations are wrapped in spans |
| 62 | +- Spans include relevant contextual fields |
| 63 | +- Log output shows hierarchical structure at command level |
| 64 | +- E2E tests pass with new spans |
| 65 | + |
| 66 | +#### Files to Modify |
| 67 | + |
| 68 | +- `src/commands/provision.rs` |
| 69 | +- `src/commands/configure.rs` |
| 70 | +- `src/commands/test.rs` |
| 71 | +- `Cargo.toml` (if needed) |
| 72 | + |
| 73 | +--- |
| 74 | + |
| 75 | +### Phase 2: Steps (Level 2) - Core Operations |
| 76 | + |
| 77 | +**Status**: 🔴 **Not Started** |
| 78 | +**Priority**: High |
| 79 | +**Estimated Effort**: 3-4 days |
| 80 | + |
| 81 | +#### Infrastructure Steps |
| 82 | + |
| 83 | +- [ ] **2.1** `InitializeInfrastructureStep::execute()` |
| 84 | + |
| 85 | + - File: `src/steps/infrastructure/initialize.rs` |
| 86 | + - Span: `initialize_infrastructure` |
| 87 | + - Fields: `step_type="infrastructure"`, `operation="init"` |
| 88 | + |
| 89 | +- [ ] **2.2** `PlanInfrastructureStep::execute()` |
| 90 | + |
| 91 | + - File: `src/steps/infrastructure/plan.rs` |
| 92 | + - Span: `plan_infrastructure` |
| 93 | + - Fields: `step_type="infrastructure"`, `operation="plan"` |
| 94 | + |
| 95 | +- [ ] **2.3** `ApplyInfrastructureStep::execute()` |
| 96 | + |
| 97 | + - File: `src/steps/infrastructure/apply.rs` |
| 98 | + - Span: `apply_infrastructure` |
| 99 | + - Fields: `step_type="infrastructure"`, `operation="apply"`, `auto_approve` |
| 100 | + |
| 101 | +- [ ] **2.4** `GetInstanceInfoStep::execute()` |
| 102 | + - File: `src/steps/infrastructure/get_instance_info.rs` |
| 103 | + - Span: `get_instance_info` |
| 104 | + - Fields: `step_type="infrastructure"`, `operation="info"` |
| 105 | + |
| 106 | +#### Rendering Steps |
| 107 | + |
| 108 | +- [ ] **2.5** `RenderOpenTofuTemplatesStep::execute()` |
| 109 | + |
| 110 | + - File: `src/steps/rendering/opentofu_templates.rs` |
| 111 | + - Span: `render_opentofu_templates` |
| 112 | + - Fields: `step_type="rendering"`, `template_type="opentofu"` |
| 113 | + |
| 114 | +- [ ] **2.6** `RenderAnsibleTemplatesStep::execute()` |
| 115 | + - File: `src/steps/rendering/ansible_templates.rs` |
| 116 | + - Span: `render_ansible_templates` |
| 117 | + - Fields: `step_type="rendering"`, `template_type="ansible"` |
| 118 | + |
| 119 | +#### System Steps |
| 120 | + |
| 121 | +- [ ] **2.7** `WaitForCloudInitStep::execute()` |
| 122 | + - File: `src/steps/system/wait_cloud_init.rs` |
| 123 | + - Span: `wait_cloud_init` |
| 124 | + - Fields: `step_type="system"`, `component="cloud_init"` |
| 125 | + |
| 126 | +#### Connectivity Steps |
| 127 | + |
| 128 | +- [ ] **2.8** `WaitForSSHConnectivityStep::execute()` |
| 129 | + - File: `src/steps/connectivity/wait_ssh_connectivity.rs` |
| 130 | + - Span: `wait_ssh_connectivity` |
| 131 | + - Fields: `step_type="connectivity"`, `protocol="ssh"` |
| 132 | + |
| 133 | +#### Software Steps |
| 134 | + |
| 135 | +- [ ] **2.9** `InstallDockerStep::execute()` |
| 136 | + |
| 137 | + - File: `src/steps/software/docker.rs` |
| 138 | + - Span: `install_docker` |
| 139 | + - Fields: `step_type="software"`, `component="docker"`, `method="ansible"` |
| 140 | + |
| 141 | +- [ ] **2.10** `InstallDockerComposeStep::execute()` |
| 142 | + - File: `src/steps/software/docker_compose.rs` |
| 143 | + - Span: `install_docker_compose` |
| 144 | + - Fields: `step_type="software"`, `component="docker_compose"`, `method="ansible"` |
| 145 | + |
| 146 | +#### Validation Steps |
| 147 | + |
| 148 | +- [ ] **2.11** All validation steps in `src/steps/validation/` |
| 149 | + - Consistent naming: `validate_{component}` |
| 150 | + - Fields: `step_type="validation"`, `component="{name}"` |
| 151 | + |
| 152 | +#### Acceptance Criteria |
| 153 | + |
| 154 | +- All step-level operations are wrapped in spans |
| 155 | +- Steps nest properly under command spans |
| 156 | +- Spans include operation types and relevant contextual information |
| 157 | +- Log output shows two-level hierarchy (Command → Step) |
| 158 | + |
| 159 | +#### Files to Modify |
| 160 | + |
| 161 | +- `src/steps/infrastructure/*.rs` (4 files) |
| 162 | +- `src/steps/rendering/*.rs` (2 files) |
| 163 | +- `src/steps/system/*.rs` (1 file) |
| 164 | +- `src/steps/connectivity/*.rs` (1 file) |
| 165 | +- `src/steps/software/*.rs` (2 files) |
| 166 | +- `src/steps/validation/*.rs` (3 files) |
| 167 | + |
| 168 | +--- |
| 169 | + |
| 170 | +### Phase 3: Remote Actions (Level 3) - Leaf Operations |
| 171 | + |
| 172 | +**Status**: 🔴 **Not Started** |
| 173 | +**Priority**: Medium |
| 174 | +**Estimated Effort**: 2-3 days |
| 175 | + |
| 176 | +#### Remote Action Trait |
| 177 | + |
| 178 | +- [ ] **3.1** Update `RemoteAction` trait definition |
| 179 | + - File: `src/remote_actions/mod.rs` |
| 180 | + - Add `#[instrument]` guidance to trait documentation |
| 181 | + - Consider adding span fields to trait methods |
| 182 | + |
| 183 | +#### Validation Actions |
| 184 | + |
| 185 | +- [ ] **3.2** `CloudInitValidator::execute()` |
| 186 | + |
| 187 | + - File: `src/remote_actions/cloud_init.rs` |
| 188 | + - Span: `cloud_init_validation` |
| 189 | + - Fields: `action_type="validation"`, `component="cloud_init"`, `server_ip` |
| 190 | + |
| 191 | +- [ ] **3.3** `DockerValidator::execute()` |
| 192 | + |
| 193 | + - File: `src/remote_actions/docker.rs` |
| 194 | + - Span: `docker_validation` |
| 195 | + - Fields: `action_type="validation"`, `component="docker"`, `server_ip` |
| 196 | + |
| 197 | +- [ ] **3.4** `DockerComposeValidator::execute()` |
| 198 | + - File: `src/remote_actions/docker_compose.rs` |
| 199 | + - Span: `docker_compose_validation` |
| 200 | + - Fields: `action_type="validation"`, `component="docker_compose"`, `server_ip` |
| 201 | + |
| 202 | +#### Acceptance Criteria |
| 203 | + |
| 204 | +- All remote actions are wrapped in spans |
| 205 | +- Remote actions nest properly under step spans |
| 206 | +- Complete three-level hierarchy visible in logs |
| 207 | +- Server IP and component information tracked in spans |
| 208 | + |
| 209 | +#### Files to Modify |
| 210 | + |
| 211 | +- `src/remote_actions/mod.rs` |
| 212 | +- `src/remote_actions/cloud_init.rs` |
| 213 | +- `src/remote_actions/docker.rs` |
| 214 | +- `src/remote_actions/docker_compose.rs` |
| 215 | + |
| 216 | +--- |
| 217 | + |
| 218 | +### Phase 4: Optimization & Documentation |
| 219 | + |
| 220 | +**Status**: 🔴 **Not Started** |
| 221 | +**Priority**: Low |
| 222 | +**Estimated Effort**: 1-2 days |
| 223 | + |
| 224 | +#### Documentation |
| 225 | + |
| 226 | +- [ ] **4.1** Update contributing guidelines |
| 227 | + |
| 228 | + - File: `docs/contributing/README.md` |
| 229 | + - Add span instrumentation guidelines |
| 230 | + - Document field naming conventions |
| 231 | + |
| 232 | +- [ ] **4.2** Create logging development guide |
| 233 | + |
| 234 | + - File: `docs/contributing/logging-guidelines.md` |
| 235 | + - Span usage examples |
| 236 | + - Field naming standards |
| 237 | + - Debugging techniques |
| 238 | + |
| 239 | +- [ ] **4.3** Update testing documentation |
| 240 | + - File: `docs/contributing/testing.md` |
| 241 | + - How to test with spans |
| 242 | + - Log assertion examples |
| 243 | + |
| 244 | +#### Code Optimization |
| 245 | + |
| 246 | +- [ ] **4.4** Review and optimize span fields |
| 247 | + |
| 248 | + - Remove redundant fields |
| 249 | + - Ensure consistent naming across components |
| 250 | + - Add missing contextual information |
| 251 | + |
| 252 | +- [ ] **4.5** Performance testing |
| 253 | + |
| 254 | + - Measure span overhead |
| 255 | + - Optimize high-frequency operations |
| 256 | + - Document performance impact |
| 257 | + |
| 258 | +- [ ] **4.6** Integration testing |
| 259 | + - Test with different tracing subscribers |
| 260 | + - Verify JSON output format |
| 261 | + - Test log filtering capabilities |
| 262 | + |
| 263 | +#### Acceptance Criteria |
| 264 | + |
| 265 | +- Complete documentation for span usage |
| 266 | +- Performance impact documented and acceptable |
| 267 | +- All logging guidelines updated |
| 268 | +- Integration tests pass with various subscribers |
| 269 | + |
| 270 | +--- |
| 271 | + |
| 272 | +## 📊 Progress Tracking |
| 273 | + |
| 274 | +### Overall Progress |
| 275 | + |
| 276 | +- **Total Tasks**: 25 |
| 277 | +- **Completed**: 0 (0%) |
| 278 | +- **In Progress**: 0 (0%) |
| 279 | +- **Not Started**: 25 (100%) |
| 280 | + |
| 281 | +### Phase Progress |
| 282 | + |
| 283 | +| Phase | Status | Tasks Complete | Progress | |
| 284 | +| ----------------------- | -------------- | -------------- | -------- | |
| 285 | +| Phase 1: Commands | 🔴 Not Started | 0/4 | 0% | |
| 286 | +| Phase 2: Steps | 🔴 Not Started | 0/11 | 0% | |
| 287 | +| Phase 3: Remote Actions | 🔴 Not Started | 0/4 | 0% | |
| 288 | +| Phase 4: Optimization | 🔴 Not Started | 0/6 | 0% | |
| 289 | + |
| 290 | +## 🛠️ Technical Implementation Details |
| 291 | + |
| 292 | +### Span Naming Conventions |
| 293 | + |
| 294 | +```rust |
| 295 | +// Commands (Level 1) |
| 296 | +#[instrument( |
| 297 | + name = "{operation}_command", |
| 298 | + skip_all, |
| 299 | + fields( |
| 300 | + command_type = "{type}" |
| 301 | + ) |
| 302 | +)] |
| 303 | + |
| 304 | +// Steps (Level 2) |
| 305 | +#[instrument( |
| 306 | + name = "{action}_{component}", |
| 307 | + skip_all, |
| 308 | + fields( |
| 309 | + step_type = "{category}", |
| 310 | + operation = "{operation}" |
| 311 | + ) |
| 312 | +)] |
| 313 | + |
| 314 | +// Remote Actions (Level 3) |
| 315 | +#[instrument( |
| 316 | + name = "{component}_{operation}", |
| 317 | + skip(self), |
| 318 | + fields( |
| 319 | + action_type = "{type}", |
| 320 | + component = "{component}", |
| 321 | + server_ip = %server_ip |
| 322 | + ) |
| 323 | +)] |
| 324 | +``` |
| 325 | + |
| 326 | +### Field Standards |
| 327 | + |
| 328 | +- **command_type**: `provision`, `configure`, `test` |
| 329 | +- **step_type**: `infrastructure`, `rendering`, `system`, `connectivity`, `software`, `validation` |
| 330 | +- **operation**: `init`, `plan`, `apply`, `render`, `install`, `validate`, `wait` |
| 331 | +- **component**: `opentofu`, `ansible`, `docker`, `cloud_init`, `ssh` |
| 332 | + |
| 333 | +### Dependencies |
| 334 | + |
| 335 | +```toml |
| 336 | +[dependencies] |
| 337 | +tracing = { version = "0.1", features = ["attributes"] } |
| 338 | +``` |
| 339 | + |
| 340 | +## 🧪 Testing Strategy |
| 341 | + |
| 342 | +### Unit Tests |
| 343 | + |
| 344 | +- Verify spans are created correctly |
| 345 | +- Test span field values |
| 346 | +- Ensure nested span relationships |
| 347 | + |
| 348 | +### Integration Tests |
| 349 | + |
| 350 | +- Test full workflow span hierarchy |
| 351 | +- Verify log output structure |
| 352 | +- Test with different tracing subscribers |
| 353 | + |
| 354 | +### E2E Tests |
| 355 | + |
| 356 | +- Run existing E2E tests with spans enabled |
| 357 | +- Verify performance impact is acceptable |
| 358 | +- Test log correlation and filtering |
| 359 | + |
| 360 | +## 📈 Success Metrics |
| 361 | + |
| 362 | +- [ ] **Hierarchical Structure**: Clear three-level nesting in logs |
| 363 | +- [ ] **Performance**: <10% overhead in E2E test execution time |
| 364 | +- [ ] **Compatibility**: Works with console and JSON subscribers |
| 365 | +- [ ] **Debugging**: Faster issue identification and resolution |
| 366 | +- [ ] **Monitoring**: Better observability for production deployments |
| 367 | + |
| 368 | +## 🔄 Review Process |
| 369 | + |
| 370 | +### Code Review Checklist |
| 371 | + |
| 372 | +- [ ] Span names follow naming conventions |
| 373 | +- [ ] Required fields are present and consistent |
| 374 | +- [ ] `skip` parameters used appropriately |
| 375 | +- [ ] Documentation updated for new spans |
| 376 | +- [ ] Tests updated and passing |
| 377 | + |
| 378 | +### Testing Requirements |
| 379 | + |
| 380 | +- [ ] Unit tests pass for instrumented functions |
| 381 | +- [ ] E2E tests show proper span hierarchy |
| 382 | +- [ ] Performance tests show acceptable overhead |
| 383 | +- [ ] Multiple subscriber formats tested |
| 384 | + |
| 385 | +--- |
| 386 | + |
| 387 | +**Next Steps**: Begin Phase 1 implementation with `ProvisionCommand` instrumentation. |
| 388 | + |
| 389 | +**Dependencies**: None - can start immediately with existing tracing setup. |
| 390 | + |
| 391 | +**Risk Assessment**: Low - Non-breaking changes, backward compatible, can be implemented incrementally. |
0 commit comments