You've already forked OrthoRoute
mirror of
https://github.com/bbenchoff/OrthoRoute.git
synced 2026-08-26 07:15:14 +00:00
- 3,311 GPU paths profiled across 40 iterations - GPU Dijkstra kernel: 16ms avg (5% of per-net time) - Python->CUDA MULTI-LAUNCH loop: ~296ms avg (95% of per-net time) - PERSISTENT KERNEL already compiled but not activated — fix is #1 priority - Via rebuild (_rebuild_via_usage_from_committed): 275ms avg, 1% of total - Expected speedup if persistent kernel activated: 10-20x (44min -> 3-5min) Updated docs/optimization/: - OPTIMIZATION_QUICK_REF.md: corrected priority table, GPU architecture notes - optimization_baseline_2026-04-03.md: GPU analysis section, revised roadmap - README.md: corrected targets and phases
94 lines
3.2 KiB
Markdown
94 lines
3.2 KiB
Markdown
# Current Logging Mechanism Review
|
||
|
||
**Date**: April 3, 2026
|
||
**File Analyzed**: `orthoroute/algorithms/manhattan/unified_pathfinder.py` (5,967 lines)
|
||
|
||
---
|
||
|
||
## Summary
|
||
|
||
OrthoRoute uses standard Python `logging` module with **287 logger calls** in `unified_pathfinder.py` alone. Produces **799 MB log files** for a 44-minute routing run due to no verbosity control — all messages always output regardless of importance.
|
||
|
||
---
|
||
|
||
## Logging Infrastructure
|
||
|
||
**Logger setup** (`unified_pathfinder.py` line 537):
|
||
```python
|
||
import logging
|
||
logger = logging.getLogger(__name__)
|
||
```
|
||
|
||
**Centralized configuration** (`shared/utils/logging_utils.py`):
|
||
- `setup_logging(settings: LoggingSettings)` — main configuration
|
||
- Dual output: Console (WARNING only) + File (DEBUG)
|
||
- Rotating file handler (prevents Windows locking issues)
|
||
- UTF-8 encoding with `errors="replace"`
|
||
|
||
---
|
||
|
||
## Logging Usage Statistics
|
||
|
||
| Level | Count | Percentage | Use |
|
||
|-------|-------|------------|-----|
|
||
| `logger.debug` | 134 | 51.3% | Algorithm internals, ROI details, cost updates, config banner, init details |
|
||
| `logger.info` | 61 | 23.4% | Remaining informational messages |
|
||
| **`logger.warning`** | **66** | **25.3%** | **Key milestones (startup, lattice, CSR, routing complete), GPU fallback, conflicts** |
|
||
| `logger.error` | 26 | 10.0% | Violations, accounting bugs, critical issues |
|
||
| **TOTAL** | **287** | | |
|
||
|
||
**Reclassification applied (April 3, 2026)**: 18 INFO→WARNING (milestones), 81 INFO→DEBUG (verbose/per-net), 1 WARNING→DEBUG (greedy progress spam). Console now shows ~66 WARNING lines per run instead of 160+ INFO lines.
|
||
|
||
---
|
||
|
||
## Existing Tag System
|
||
|
||
Good categorization tags already in use:
|
||
- `[ITER X]` — Iteration progress
|
||
- `[CONVERGENCE]` — Convergence metrics
|
||
- `[CONFIG]` — Configuration display
|
||
- `[GPU]` — GPU operations
|
||
- `[VIA-POOL]` — Via pooling system
|
||
- `[LAYER-MAP]` — Layer mapping
|
||
- `[ACCOUNTING]` — Accounting checks
|
||
- `[ROI]` — Region of interest
|
||
- `[MANHATTAN-VIOLATION]` — Constraint violations
|
||
- `[BOUNDS]` — Board bounds
|
||
- `[EXCLUDE]` — Net exclusion
|
||
- `[CLEAN]` — Final cleanup
|
||
|
||
---
|
||
|
||
## Problematic Patterns
|
||
|
||
### 1. Per-Iteration INFO Spam
|
||
**Lines**: 3691, 3795, 3913, 3973
|
||
64 iterations × 3+ messages = 192+ INFO lines of iteration noise.
|
||
|
||
### 2. Greedy Per-Net Progress
|
||
**Line**: 4558
|
||
512 nets ÷ 25 = 20+ `logger.warning` lines in iteration 1 alone.
|
||
|
||
### 3. ROI Debug Spam
|
||
**Lines**: 1600, 1615, 1681
|
||
512 nets × 64 iterations × 2 messages = **65,536 debug lines**.
|
||
|
||
### 4. Config Banner
|
||
**Lines**: 2106–2117
|
||
15+ `logger.info` lines printed every run regardless of whether config details are needed.
|
||
|
||
---
|
||
|
||
## What Was Fixed (April 3, 2026)
|
||
|
||
- ✅ Logging reclassification applied — 100 calls reclassified
|
||
- ✅ Key milestones now visible on console (WARNING)
|
||
- ✅ Verbose/per-net messages demoted to DEBUG (file only)
|
||
- ✅ Greedy per-net progress (`[ITER 1 - GREEDY] Routing N/total...`) demoted to DEBUG
|
||
|
||
## What Remains
|
||
|
||
- `@profile_time` not yet applied to core algorithm functions in `unified_pathfinder.py`
|
||
- No conditional `if condition:` guards before expensive log format calls in hot paths
|
||
- Per-net ROI messages (512×/iteration) still at DEBUG — add guards if file size still excessive after re-test
|