Logging: fix live-console tearing (single-owner stdout) + suppressible filters for runtime debug spam#403
Merged
Conversation
… torn console) PR #402 moved console log emit onto a dedicated writer thread, but BarGoLink still printf()+fflush()ed its progress bars straight to stdout on the loading/world thread. Two unsynchronized writers on one stdout made the "=== N%" bars and the writer thread's log lines interleave character-by- character -> the torn live console. The file log was unaffected (the bar never writes to the file and file writes are m_fileMtx-serialized). The race also recurs at runtime via .reload/.ahbot/playerbot commands that step bars on the world thread while the writer is live, so a writer-start-timing fix alone is insufficient. Make stdout single-owner: the bar now builds one full redraw string and hands it to the writer as a single atomic "raw" record (verbatim - no time prefix, no color, no appended newline), so bar redraws and log lines flow through one FIFO in program order, exactly as before the writer existed. - ProgressBarRender.h (new): pure, dependency-free byte builders, byte-identical to the legacy printf sequences (offline unit test, incl. an n>indic_len guard). - ProgressBar.{h,cpp}: init/step/dtor build one string and emit via a swappable sink; the default sink is a synchronous fwrite(stdout)+fflush, so offline tools and realmd stay byte-for-byte unchanged. - Log.{h,cpp}: ConsoleEmitRaw() enqueues a raw record when the writer runs, else writes verbatim synchronously. ConsoleLogRecord gains isRaw. - ConsoleLogWriter.cpp: Emit honours isRaw (verbatim, no '\n'); the queue-full drop notice gets a leading '\n' so it can no longer land mid-bar. - mangosd.cpp: install the async bar sink right after StartConsoleThread(). Colored output (including the ScriptDev banner) is untouched - only the bar, which was never colored, changed path. Built clean (RelWithDebInfo, mangosd + realmd, 0 errors) and confirmed torn-free in a live smoke test. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
…writer review fixes
Two related logging improvements on top of the off-thread console writer.
1) LOG-FILTER SWEEP -- make a busy LogLevel/LogFileLevel=3 run usable.
- New filters LogFilter_GridAdd (0x100000) and LogFilter_DbScripts (0x200000);
LOG_FILTER_COUNT -> 22. ALL log filters now ship default-on (suppressed) so a
fresh level-3 run is quiet out of the box; set any LogFilter_* = 0 to restore
that category. ConfVersion bumped so stale configs get the out-of-date notice.
- Gated the highest-volume bare DEBUG_LOG/DETAIL_LOG/outString runtime lines onto
EXISTING filters (no new bits beyond the two above):
SPELL_CAST : "Holder of spell .. in use" (Unit), "Spell Effect DUMMY" x2
COMBAT : SMSG_ATTACKSTART (now logs attacker -> victim via GetGuidStr)
MAP_LOADING : grid load-content count, grid IDLE/REMOVAL + differed-unload
transitions, both vmap GetHitPosition LoS corrections,
AddPersistentState, and the startup "Active Flag" line
DB_STRICTED_CHECK: the four "Unused (> MaxPlayerLevel) level" notices
GRID_ADD : "X enters grid[x,y]"
DB_SCRIPTS : db_scripts process traces
Error variants (outError/outErrorDb) and one-time/info lines stay visible.
- Fixed a latent config-key typo: logFilterData read "LogFilter_MapLoading" but
every config ships "LogFilter_MapsLoading", so the key never bound and the
filter only worked by code default. Code now reads "LogFilter_MapsLoading".
- GridStates: corrected the mislabeled "moved to IDLE state" -> "REMOVAL state"
(IdleState::Update actually transitions to GRID_STATE_REMOVAL).
2) CONSOLE-WRITER REVIEW FIXES (adversarial review of the bar-tearing change).
- Single-owner stdout: the bar was made async, but the CLI prompt, CLI command
output (utf8print), the beep, and the loglevel-change notices still wrote to
stdout directly -- so they could overtake queued bar frames (e.g. the prompt
reprinted after .reload landing before/over the bar). All now route through
Log::ConsoleEmitRaw, so every non-log-line console write shares the one FIFO
and drains in program order. (Log::outTime's printf is dead -- no callers.)
- ProgressBarRender.h: include <cstddef> and use std::size_t (do not rely on
<string> to expose ::size_t globally -- non-portable on GCC/Clang).
Built clean (RelWithDebInfo, mangosd + realmd, 0 errors); filters and the .reload
prompt-ordering fix confirmed in live level-3 smoke tests.
Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Up to standards ✅🟢 Issues
|
| Metric | Results |
|---|---|
| Complexity | 7 |
| Duplication | 0 |
NEW Get contextual insights on your PRs based on Codacy's metrics, along with PR and Jira context, without leaving GitHub. Enable AI reviewer
TIP This summary will be updated as you push new changes.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Two related logging improvements on top of the off-thread console writer (#402):
stdoutwriters) for the console; this makesstdoutsingle-owner so output can no longer interleave or overtake itself.LogLevel/LogFileLevel = 3usable — gate the highest-volume runtime debug lines behind log filters (all default-suppressed), so a busy level-3 run is readable out of the box.Problem
After #402 moved console log emit onto a dedicated writer thread,
BarGoLinkprogress bars stillprintf'd straight tostdouton the loading/world thread — two unsynchronized writers on one stream → the live console tore character-by-character (timestamps spliced through=== N%bars). The file log was unaffected (the bar never writes to file; file writes are mutex-serialized).An adversarial review then found that making the bar async let other synchronous direct-
stdoutwriters — themangos>prompt, CLI command output, the loglevel notices — overtake queued bar frames (e.g. the prompt reprinted after.reloadlanding on top of the bars).Changes
Console writer / tearing fix
ProgressBarRender.h: pure, dependency-free byte builders, byte-identical to the legacyprintfsequences (offline unit test, incl. ann > indic_lenguard).BarGoLink::init/step/~BarGoLinkbuild one string per redraw and emit via a swappable sink; the default sink is a synchronousfwrite(stdout)+fflush, so offline tools and realmd are unchanged.Log::ConsoleEmitRaw()enqueues the bar as a single atomic raw record (no time prefix, no color, no trailing newline) when the writer runs, else writes verbatim synchronously.stdout: the CLI prompt, CLI command output (utf8print), the beep, and theSetLogLevel/SetLogFileLevelnotices now route throughConsoleEmitRawtoo — everything drains through one FIFO in program order.ProgressBarRender.h:#include <cstddef>+std::size_t(portability; don't rely on<string>exposing::size_t).Log-filter sweep
LogFilter_GridAddandLogFilter_DbScripts; all log filters now ship default-on (suppressed).ConfVersionbumped so stale configs get the out-of-date notice.DEBUG_LOG/DETAIL_LOG/outStringlines gated onto existing filters (no new bits beyond the two above):SPELL_CAST(spell holder / dummy effects),COMBAT(SMSG_ATTACKSTART),MAP_LOADING(grid load/idle/unload, vmap LoS corrections, persistent-state, the startup "Active Flag" line),DB_STRICTED_CHECK(over-cap level notices).outError/outErrorDb) and one-time/info lines are deliberately left visible.LogFilter_MapLoadingbut every config shipsLogFilter_MapsLoading, so the key never bound (filter worked only by code default). Code now readsLogFilter_MapsLoading.SMSG_ATTACKSTARTnow logsattacker -> victim(viaGetGuidStr()) — handy for diagnosing NPC-vs-NPC combat with no players online.GridStates: corrected the mislabeled"moved to IDLE state"→"REMOVAL state"(IdleState::Updateactually transitions toGRID_STATE_REMOVAL).Testing
mangosd+realmd, 0 errors..reload allprompt ordering correct, filter toggles verified.size_t) addressed; no findings in the filter/config changes.Compatibility
LogFilter_GridAdd/LogFilter_DbScriptskeys added to the dist config with safe defaults; existing configs work unchanged (missing keys fall back to the code default).LogLevel=1+LogFileLevel=3. Set anyLogFilter_* = 0to restore that category.🤖 Generated with Claude Code
This change is