nc_program_manager/.paul/phases/15-logging/15-01-SUMMARY.md
dtrentin 60ce1c9d57 feat(15-logging): NLog structured logging — all output through NLog (v0.5 complete)
Phase 15 complete (2 plans):
- 15-01: NLog 5.2.8 + nlog.config (rolling file daily/7d + console); logger fields in
  FanucMachine, HeidenhainMachine, SiemensMachine, MitsubishiMachine, Lsv2Client, Program.cs;
  SetState event handler catches → _log.Warn; cleanup catches annotated; ISS-003/ISS-004 closed
- 15-02: All Console.Write/WriteLine in Program.cs replaced with _log.Info (103 calls);
  nlog.config console target layout=${message}, levels=Info only — Warn/Error file-only;
  operator console output identical; every interaction now timestamped in log file

Milestone v0.5 Operational Quality complete.

Co-Authored-By: Claude <noreply@anthropic.com>
2026-05-18 23:57:27 +02:00

159 lines
6.7 KiB
Markdown
Raw Permalink Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

---
phase: 15-logging
plan: 01
subsystem: observability
tags: [nlog, logging, exception-handling, csharp, net472]
requires:
- phase: 14-test-hardening
provides: stable test base, no regressions introduced
provides:
- NLog 5.2.8 wired into all 4 machine classes and Program.cs
- Rolling file log (daily, 7 days) + console (Warn+)
- Event handler catches surface to log instead of silent swallow
- Cleanup catches annotated as intentionally silent
affects: future-phases, deployment, support
tech-stack:
added: [NLog 5.2.8]
patterns: [static readonly Logger per class via LogManager.GetCurrentClassLogger()]
key-files:
created: [nlog.config]
modified:
- packages.config
- NcProgramManager.csproj
- Program.cs
- Cnc/Fanuc/FanucMachine.cs
- Cnc/Heidenhain/HeidenhainMachine.cs
- Cnc/Heidenhain/Lsv2Client.cs
- Cnc/Siemens/SiemensMachine.cs
- Cnc/Mitsubishi/MitsubishiMachine.cs
key-decisions:
- "NLog console target minlevel=Warn — logger output does not duplicate operator Console.WriteLine"
- "Dispose/cleanup catches: comment-only, no log calls — Dispose must not throw"
- "throwConfigExceptions=true in nlog.config — config errors surface at startup"
patterns-established:
- "Logger field: private static readonly Logger _log = LogManager.GetCurrentClassLogger();"
- "Event handler catch: catch (Exception ex) { _log.Warn(ex, 'StateChanged handler threw'); }"
- "Cleanup catch annotation: catch { /* cleanup — intentionally swallowed */ }"
duration: ~30min
started: 2026-05-18T00:00:00Z
completed: 2026-05-18T00:00:00Z
---
# Phase 15 Plan 01: Logging Summary
**NLog 5.2.8 wired into all 5 production classes; rolling file log + console target; event handler silent swallows surfaced; cleanup swallows annotated.**
## Performance
| Metric | Value |
|--------|-------|
| Duration | ~30 min |
| Tasks | 3 completed |
| Files created | 1 (nlog.config) |
| Files modified | 8 |
## Acceptance Criteria Results
| Criterion | Status | Notes |
|-----------|--------|-------|
| AC-1: NLog config present and wired | Pass | nlog.config created; Content/CopyAlways in csproj; NLog 5.2.8 in packages.config |
| AC-2: Event handler exceptions reach log | Pass | All 4 SetState catches → `_log.Warn(ex, "StateChanged handler threw")`; zero silent handler catches remain |
| AC-3: Dispose cleanup catches annotated | Pass | All Dispose/disconnect cleanup catches have `/* cleanup — intentionally swallowed */`; no log call in Dispose |
| AC-4: Program.cs errors reach log file | Pass | 3× `_log.Error(ex, ...)` added before Console.WriteLine in arg-parse, Scarica, Invia catch blocks; 97× Console.WriteLine unchanged |
## Accomplishments
- ISS-003 addressed: all event handler silent swallows surfaced; cleanup swallows intentionally annotated
- ISS-004 addressed: NLog rolling file + console logging wired into all production classes
- 97 operator-facing `Console.WriteLine` calls unchanged — zero behavior change for operators
- Lsv2Client also gains Info-level connect/disconnect tracing
## Files Created/Modified
| File | Change | Purpose |
|------|--------|---------|
| `nlog.config` | Created | Rolling daily file target + Warn+ console; 7-day archive |
| `packages.config` | Modified | NLog 5.2.8 entry added |
| `NcProgramManager.csproj` | Modified | NLog Reference with HintPath; nlog.config as Content/CopyAlways |
| `Program.cs` | Modified | `using NLog;`, `_log` field, 3× `_log.Error` in catch blocks |
| `Cnc/Fanuc/FanucMachine.cs` | Modified | Logger field, SetState fix, cleanup catch annotations |
| `Cnc/Heidenhain/HeidenhainMachine.cs` | Modified | Logger field, SetState fix, Dispose annotations |
| `Cnc/Heidenhain/Lsv2Client.cs` | Modified | Logger field, Info logging at connect/disconnect, cleanup annotations |
| `Cnc/Siemens/SiemensMachine.cs` | Modified | Logger field, SetState fix, Dispose annotations |
| `Cnc/Mitsubishi/MitsubishiMachine.cs` | Modified | Logger field, SetState fix, Dispose annotations |
## Decisions Made
| Decision | Rationale | Impact |
|----------|-----------|--------|
| Console target minlevel=Warn | Logger output must not duplicate operator Console.WriteLine (98+ calls are user-facing) | Operators see only their output; log file captures all Debug+ |
| No logging in Dispose/cleanup catches | Dispose must not throw; logging infrastructure could itself fail | Cleanup stays silent, marked with comment for code reviewers |
| throwConfigExceptions=true | Surfaces nlog.config errors at startup rather than silently failing | Config mistakes visible immediately |
| NLog 5.2.8 / net46 DLL | .NET 4.7.2 target; net46 is highest .NET Framework lib in NLog 5.x package | Build compatible without targeting pack changes |
## Deviations from Plan
### Summary
| Type | Count | Impact |
|------|-------|--------|
| Scope additions | 2 | Minor — consistent with AC-3 intent |
| Deferred | 0 | — |
### Scope Additions
**1. FanucMachine ConnectCore cancellation cleanup catch annotated**
- `try { Focas1.cnc_freelibhndl(_hndl); } catch { }` in ConnectCore cancellation path
- Plan only named Dispose catches; this is also fire-and-forget cleanup
- Annotated with `/* cleanup — intentionally swallowed */` for consistency
**2. FanucMachine Record() disconnect cleanup catch annotated**
- `try { Focas1.cnc_freelibhndl(_hndl); } catch { }` in Record() disconnect error path
- Same rationale as above — fire-and-forget, not event handler
- Annotated consistently
## Verification Results
```
grep -c "NLog" packages.config → 1 ✓
grep -c "NLog" NcProgramManager.csproj → 2 (Reference + Content) ✓
nlog.config exists ✓
LogManager.GetCurrentClassLogger() in all 5 files ✓
try { h(this, next); } catch { } → 0 occurrences remain ✓
_log.Warn(ex in 4 machine classes (1 each) ✓
_log.Error in Program.cs → 3 ✓
Console.WriteLine count → 97 (unchanged) ✓
```
## Issues Closed
| Issue | Status |
|-------|--------|
| ISS-003: Silent exception handlers | Closed — event handler catches logged; cleanup catches annotated |
| ISS-004: No logging framework | Closed — NLog 5.2.8 rolling file + console wired |
## Next Phase Readiness
**Ready:**
- All production classes have NLog logger
- Log file at `logs/nc_program_manager.log` next to EXE
- Pattern established for future classes: `private static readonly Logger _log = LogManager.GetCurrentClassLogger();`
**Concerns:**
- No build verification on Linux (no dotnet/msbuild) — NLog DLL path assumes NuGet restore to `packages\NLog.5.2.8\lib\net46\`; must restore on Windows before first build
- ISS-002 (blocking `.GetAwaiter().GetResult()`) still open — separate phase
**Blockers:**
- None for code; Windows NuGet restore needed before first build with NLog
---
*Phase: 15-logging, Plan: 01*
*Completed: 2026-05-18*