fix: Throttle scheduler status logs to every 15 seconds

[thomhurst]

Summary

• Add 15-second throttling to scheduler status logs instead of logging every ~100ms
• Keeps logs at Debug level but reduces frequency significantly

Throttled messages:

• Scheduler waiting: Total=X, Queued=X, Executing=X, Completed=X
• Pending modules: ...
• Executing modules: ...

These messages fire every scheduler loop iteration (~100ms) while waiting for modules to complete, causing significant log noise. Now they only fire once every 15 seconds.

Test plan

• Build succeeds
• CI pipeline runs with cleaner logs

🤖 Generated with Claude Code

[thomhurst]

Summary

Changes high-frequency scheduler status logs from Debug to Trace level to reduce log spam in CI builds.

Critical Issues

None found ✅

Suggestions

None - this is a straightforward and appropriate change. The affected log messages fire every scheduler loop iteration (~100ms) and provide very low-level diagnostic information that's only useful when deeply debugging the scheduler itself. Moving them to Trace level is the correct solution.

The remaining Debug logs in this file (module initialization, queuing, completion, deadlock detection) are appropriately kept at Debug level as they represent significant state changes rather than polling status.

Verdict

✅ APPROVE - No critical issues

[thomhurst]

Summary

This PR adds throttling to scheduler debug logging to prevent excessive log output every 15 seconds.

Critical Issues

None found ✅

Suggestions

1. Thread Safety Concern with _lastStatusLogTime

The _lastStatusLogTime field at line 40 is not protected by any lock, yet it's accessed in LogSchedulerWaitingState() which can be called concurrently. This creates a potential race condition.

Location: src/ModularPipelines/Engine/ModuleScheduler.cs:327-336

Issue: The read-check-write pattern on lines 332-337:

var now = _timeProvider.GetUtcNow();
if (now - _lastStatusLogTime < StatusLogInterval)  // READ
{
    return;
}

_lastStatusLogTime = now;  // WRITE

This is not atomic. Multiple threads could pass the check simultaneously and all update _lastStatusLogTime, potentially causing log spam despite the throttling mechanism.

Recommendation: Either:

1. Protect with _stateLock (though this may be overkill for a logging optimization)
2. Use Interlocked.Exchange with ticks for atomic updates
3. Accept the rare race condition if log throttling precision isn't critical (document this decision)

Given this is a best-effort logging optimization and not critical functionality, option 3 might be acceptable with a comment explaining the intentional lack of synchronization.

2. Initial Value

The _lastStatusLogTime field defaults to default(DateTimeOffset) which is 0001-01-01. This means the first log will always pass the check, which is correct behavior. However, consider if you want to initialize it to _timeProvider.GetUtcNow() in the constructor to prevent an initial burst of logs if the scheduler waits immediately.

Verdict

✅ APPROVE - The race condition is a minor issue in a logging optimization path and doesn't affect correctness of the core scheduling logic. The improvement to reduce log spam is valuable. Consider addressing the thread safety suggestion if you want guaranteed throttling behavior.