Fix: fold simulated device logs into HostLogger

docs/dfx/host-trace.md

@@ -62,6 +62,14 @@ boundary, not a clean floor. A system tracer would hand the bytes to a consumer
 instead, and would bound its buffer and count what it drops; this does neither,
 deliberately.
 
+Every DSO that compiles the logger holds its own buffered stream on that one
+file, so the buffering above is per module rather than per process: a `WARN` from
+one module does not put another module's pending records on disk. Unloading a
+module closes its stream, so a `dlclose` — which the sim device runner performs
+on the AICPU SO at every teardown — leaves no records behind in the mapping it
+drops. A stream inherited across `fork` belongs to the parent and is left alone,
+so a child never flushes the parent's copied buffer a second time.
+
 ## Reading a run back
 
 Every record carries its own `pid`, so the tools take several inputs and

docs/logging.md

@@ -29,9 +29,9 @@ Each host module:
                   └─ simpler_host_log_bind_state(state*)
 
 Device logging:
-       AICPU keeps the device backend
-            ├─ sim: set_log_level(...) seeds its current level flags
-            └─ onboard: CANN level is sampled during device init
+       dev_vlog_* compatibility interface
+            ├─ sim: bound HostLogger → same state, envelope, and destination
+            └─ onboard: separate CANN backend sampled during device init
 ```
 
 One threshold controls `DEBUG / INFO / TIMING / WARN / ERROR`; `NUL` suppresses
@@ -59,7 +59,7 @@ src/common/platform/
 ├── include/aicpu/device_log.h               device backend declarations
 ├── shared/aicpu/unified_log_device.cpp      LOG_* ABI → dev_vlog_* adapter
 ├── onboard/aicpu/device_log.cpp             onboard CANN backend
-└── sim/aicpu/device_log.cpp                 sim AICPU stderr backend
+└── sim/aicpu/device_log.cpp                 dev_vlog_* → bound HostLogger adapter
 ```
 
 There is no standalone `libsimpler_log.so`. Host consumers compile the two
@@ -133,9 +133,11 @@ Machine-readable `[STRACE]` records satisfy that bound. Longer human-readable
 records are best-effort and may interleave across module boundaries. Blocking
 and drop accounting for those writes remain part of issue #1792 item 6.
 
-The AICPU `dev_vlog_*` functions remain separate. Sim formats a single stderr
-record; onboard forwards through CANN dlog. Folding sim's device logger into
-the host backend is tracked separately by issue #1792 item 5.
+The AICPU `dev_vlog_*` interface remains source-compatible on both platforms.
+Sim implements it as a thin `va_list` adapter into its bound `HostLogger`, so it
+shares the live threshold, envelope, destination, and fallback with the other
+host-side modules in that process. Only real-silicon AICPU retains a separate
+backend, because its records go through CANN dlog rather than a host process.
 
 ## Cross-DSO host state
 
@@ -229,16 +231,14 @@ trace/swimlane JSON while leaving event timestamps monotonic and relative. See
 ### AICPU sim
 
 ```text
-[DEBUG]  func: [file.cpp:line] message
-[INFO]   func: [file.cpp:line] message
-[TIMING] func: [file.cpp:line] message
-[WARN]   func: [file.cpp:line] message
-[ERROR]  func: [file.cpp:line] message
+[mono_ns=MONOTONIC_NS][T0xTID][LEVEL] func: [file.cpp:line] message
 ```
 
-This is still the sim device backend, so it has no host monotonic/tid prefix.
-Onboard AICPU uses the CANN dlog format. Device TIMING uses CANN WARN and adds a
-`[TIMING]` message tag.
+Sim AICPU runs on a host CPU inside the host process and uses the same envelope
+and destination as every other bound host module. The `dev_vlog_*` names remain
+as the compatibility boundary `unified_log_device.cpp` consumes. Onboard AICPU
+uses the CANN dlog format. Device TIMING uses CANN WARN and adds a `[TIMING]`
+message tag.
 
 ## Configuration flow
 
@@ -250,7 +250,7 @@ Onboard AICPU uses the CANN dlog format. Device TIMING uses CANN WARN and adds a
 | `_ChipWorker.init()` | Load sim context and host runtime, then bind each module's logger state | `src/common/worker/chip_worker.cpp` |
 | `simpler_init` | Onboard maps the bound threshold to CANN; attach and take executor binaries | `src/common/platform/{onboard,sim}/host/c_api_shared.cpp` |
 | Nested host load | Bind generated host orchestration/AICore logger state before entry | runtime maker / sim device runner |
-| AICPU init | Snapshot the applicable device threshold | platform AICPU init |
+| AICPU init | Sim binds the live host state; onboard snapshots CANN policy | platform AICPU init |
 
 The Python level is still sampled during worker initialization. Calling
 `logger.setLevel(...)` does not itself call the native setter; recreate or
@@ -321,6 +321,8 @@ There is no logger build step or logger field in `RuntimeBinaries`. Instead:
 
 - `_task_interface`, all host runtimes, sim-context, and sim AICore targets add
   `host_log.cpp` and `unified_log_host.cpp` to their source lists.
+- Sim AICPU targets add `host_log.cpp` while keeping `unified_log_device.cpp`;
+  the device ABI delegates to HostLogger there.
 - Host-compiled generated orchestration SOs receive the same sources through
   `KernelCompiler.get_orchestration_cache_inputs`; those sources therefore
   participate in the scene-test cache key.
@@ -336,7 +338,7 @@ There is no logger build step or logger field in `RuntimeBinaries`. Instead:
 | Change the user-facing level model | `python/simpler/_log.py` and `docs/testing.md` |
 | Change host output or STRACE grammar | `src/common/log/host_log.cpp` |
 | Change the shared-state ABI | `src/common/log/include/common/host_log_state.h` |
-| Change sim AICPU output | `src/common/platform/sim/aicpu/device_log.cpp` |
+| Change sim AICPU adaptation | `src/common/platform/sim/aicpu/device_log.cpp` |
 | Change onboard CANN tagging | `src/common/platform/onboard/aicpu/device_log.cpp` |
 | Add a host logging consumer | compile both host logger sources, include `src/common/log/include`, and bind state during module init |
 | Add a level | `log_level.h`, `_log.py`, `simpler_setup/log_config.py`, and AICPU `set_log_level` |

src/a2a3/platform/sim/aicpu/CMakeLists.txt

@@ -56,6 +56,7 @@ file(GLOB COMMON_SOURCES CONFIGURE_DEPENDS
     "${CMAKE_CURRENT_SOURCE_DIR}/../../../../common/platform/sim/aicpu/*.cpp"
 )
 list(APPEND AICPU_SOURCES ${COMMON_SOURCES})
+list(APPEND AICPU_SOURCES "${CMAKE_CURRENT_SOURCE_DIR}/../../../../common/log/host_log.cpp")
 
 # Then, collect sources from CUSTOM_SOURCE_DIRS (runtime sources)
 if(DEFINED CUSTOM_SOURCE_DIRS)

src/a2a3/platform/sim/host/device_runner.cpp

@@ -204,17 +204,17 @@ int DeviceRunner::ensure_binaries_loaded() {
         if (!load_sym("set_platform_scope_stats_base", reinterpret_cast<void **>(&set_platform_scope_stats_base_func_)))
             return PTO_RUNTIME_ERR_INTERNAL;
 
-        // The AICPU sim SO owns its level flags because it is RTLD_LOCAL.
-        // Forward the process-wide HostLogger threshold explicitly.
+        // The AICPU sim SO binds its private HostLogger before the compatibility
+        // level setter can emit a clock anchor.
         using SetLogLevelFunc = void (*)(int);
         SetLogLevelFunc set_log_level_func = nullptr;
         if (!load_sym("set_log_level", reinterpret_cast<void **>(&set_log_level_func))) return PTO_RUNTIME_ERR_INTERNAL;
-        set_log_level_func(HostLogger::get_instance().level());
         using SetHostLogStateFunc = void (*)(SimplerHostLogState *);
         SetHostLogStateFunc set_host_log_state_func = nullptr;
         if (!load_sym("set_host_log_state", reinterpret_cast<void **>(&set_host_log_state_func)))
             return PTO_RUNTIME_ERR_INTERNAL;
         set_host_log_state_func(HostLogger::get_instance().state());
+        set_log_level_func(HostLogger::get_instance().level());
 
         aicpu_so_loaded_ = true;
         LOG_INFO("DeviceRunner(sim): Loaded aicpu_execute from %s", aicpu_so_path_.c_str());

src/a5/platform/sim/aicpu/CMakeLists.txt

@@ -54,6 +54,7 @@ file(GLOB COMMON_SOURCES CONFIGURE_DEPENDS
     "${CMAKE_CURRENT_SOURCE_DIR}/../../../../common/platform/sim/aicpu/*.cpp"
 )
 list(APPEND AICPU_SOURCES ${COMMON_SOURCES})
+list(APPEND AICPU_SOURCES "${CMAKE_CURRENT_SOURCE_DIR}/../../../../common/log/host_log.cpp")
 
 # Then, collect sources from CUSTOM_SOURCE_DIRS (runtime sources)
 if(DEFINED CUSTOM_SOURCE_DIRS)

src/a5/platform/sim/host/device_runner.cpp

@@ -190,17 +190,17 @@ int DeviceRunner::ensure_binaries_loaded() {
         if (!load_sym("set_platform_scope_stats_base", reinterpret_cast<void **>(&set_platform_scope_stats_base_func_)))
             return PTO_RUNTIME_ERR_INTERNAL;
 
-        // The AICPU sim SO owns its level flags because it is RTLD_LOCAL.
-        // Forward the process-wide HostLogger threshold explicitly.
+        // The AICPU sim SO binds its private HostLogger before the compatibility
+        // level setter can emit a clock anchor.
         using SetLogLevelFunc = void (*)(int);
         SetLogLevelFunc set_log_level_func = nullptr;
         if (!load_sym("set_log_level", reinterpret_cast<void **>(&set_log_level_func))) return PTO_RUNTIME_ERR_INTERNAL;
-        set_log_level_func(HostLogger::get_instance().level());
         using SetHostLogStateFunc = void (*)(SimplerHostLogState *);
         SetHostLogStateFunc set_host_log_state_func = nullptr;
         if (!load_sym("set_host_log_state", reinterpret_cast<void **>(&set_host_log_state_func)))
             return PTO_RUNTIME_ERR_INTERNAL;
         set_host_log_state_func(HostLogger::get_instance().state());
+        set_log_level_func(HostLogger::get_instance().level());
 
         aicpu_so_loaded_ = true;
         LOG_INFO("DeviceRunner(sim): Loaded aicpu_execute from %s", aicpu_so_path_.c_str());

src/common/log/host_log.cpp

@@ -155,6 +155,7 @@ long host_trace_tid() {
 
 struct HostLogFileSink {
     HostLogFileSink();
+    ~HostLogFileSink();
 
     std::mutex mutex;
     FILE *stream = nullptr;
@@ -178,6 +179,18 @@ HostLogFileSink::HostLogFileSink() {
     (void)pthread_atfork(host_log_sink_before_fork, host_log_sink_after_fork, host_log_sink_after_fork);
 }
 
+// One sink per DSO that compiles this file, so each holds its own buffered
+// stream on the shared per-process log. Closing it here is what puts that
+// buffer's tail on disk when the DSO is unloaded: dlclose runs this destructor,
+// and a dlopened module's records would otherwise be discarded with its mapping.
+// A stream this process did not open belongs to the parent that forked it and
+// is left alone, so the parent's copied stdio buffer is never flushed twice.
+HostLogFileSink::~HostLogFileSink() {
+    std::scoped_lock lock(mutex);
+    if (stream != nullptr && pid == getpid()) (void)std::fclose(stream);
+    stream = nullptr;
+}
+
 // Append one already-formatted record. The <=`PIPE_BUF` single-write rule that
 // makes a stderr record indivisible neither applies nor is needed here: this file
 // has exactly one writer process and the sink mutex serializes the writers inside
@@ -242,10 +255,7 @@ namespace {
 // binds the process-owned state. Missing binding is therefore observable as an
 // absent module stream rather than output filtered at the wrong threshold.
 SimplerHostLogState g_module_log_state{
-    SIMPLER_HOST_LOG_STATE_ABI_VERSION,
-    sizeof(SimplerHostLogState),
-    static_cast<int32_t>(LogLevel::NUL),
-    0,
+    SIMPLER_HOST_LOG_STATE_ABI_VERSION, sizeof(SimplerHostLogState), static_cast<int32_t>(LogLevel::NUL), 0, 0, {},
 };
 
 int32_t atomic_load_i32(const int32_t *value) { return __atomic_load_n(value, __ATOMIC_ACQUIRE); }

src/common/platform/include/aicpu/device_log.h

@@ -14,16 +14,16 @@
  *
  * Layered design:
  *   - Low-level dev_log_*() functions are platform-specific (CANN dlog on
- *     real hardware, fprintf(stderr,...) in simulation).
+ *     real hardware, the process-owned HostLogger in simulation).
  *   - Onboard fills DEBUG/INFO/WARN/ERROR from CheckLogLevel(AICPU,...);
- *     simulation fills all flags from the host-provided threshold.
+ *     simulation queries the live threshold in its bound HostLogger state.
  *   - TIMING is a simpler level between INFO and WARN. Both backends gate it
  *     from the host threshold; onboard emits enabled messages through CANN
  *     WARN because CANN has no intermediate level.
  *
  * Platform Support:
  * - a2a3 / a5       : Real hardware with CANN dlog API
- * - a2a3sim / a5sim : Host-based simulation using fprintf(stderr,...)
+ * - a2a3sim / a5sim : Host-based simulation using HostLogger
  */
 
 #pragma once
@@ -44,22 +44,23 @@
 #endif
 
 // =============================================================================
-// Severity enable flags (defined in platform-specific device_log.cpp)
+// Platform-specific severity queries. Sim reads a live bound HostLogger state;
+// onboard reads the CANN-derived flags cached by its platform backend.
 // =============================================================================
 
-extern bool g_is_log_enable_debug;
-extern bool g_is_log_enable_info;
-extern bool g_is_log_enable_timing;
-extern bool g_is_log_enable_warn;
-extern bool g_is_log_enable_error;
+bool is_log_enable_debug();
+bool is_log_enable_info();
+bool is_log_enable_timing();
+bool is_log_enable_warn();
+bool is_log_enable_error();
 
 // =============================================================================
 // Configuration setters (called by AICPU kernel init from KernelArgs)
 // =============================================================================
 
 // Levels use Python-compatible thresholds: DEBUG=10, INFO=20, TIMING=25,
 // WARN=30, ERROR=40, NUL=60. Onboard applies the threshold to TIMING while
-// CANN owns its native levels; simulation applies it to the full flag table.
+// CANN owns its native levels; simulation updates its bound HostLogger state.
 extern "C" void set_log_level(int level);
 
 // Hand the process-owned host-log state to the simulation AICPU backend, which
@@ -78,11 +79,9 @@ int bind_orchestration_host_log_state(void *handle, const char **error);
 // Platform-specific logging functions (low-level layer)
 //
 // va_list primitives used by the unified_log_* adapter to forward a caller's
-// variadic args. Both backends format a whole record into one stack buffer and
-// emit it in a single call: sim writes it with one write(2), kept under
-// PIPE_BUF so concurrent threads / forked workers on a shared stderr never
-// interleave partial records; onboard buffers because CANN's dlog API has no
-// va_list variant. Caller owns va_start/va_end.
+// variadic args. Sim delegates formatting and destination selection to
+// HostLogger; onboard buffers because CANN's dlog API has no va_list variant.
+// Caller owns va_start/va_end.
 // =============================================================================
 
 #include <cstdarg>
@@ -94,14 +93,8 @@ void dev_vlog_warn(const char *func, const char *fmt, va_list args);
 void dev_vlog_error(const char *func, const char *fmt, va_list args);
 
 // =============================================================================
-// Helper Functions
+// Initialization
 // =============================================================================
 
-inline bool is_log_enable_debug() { return g_is_log_enable_debug; }
-inline bool is_log_enable_info() { return g_is_log_enable_info; }
-inline bool is_log_enable_timing() { return g_is_log_enable_timing; }
-inline bool is_log_enable_warn() { return g_is_log_enable_warn; }
-inline bool is_log_enable_error() { return g_is_log_enable_error; }
-
 // Initialize log switch (platform-specific implementation)
 void init_log_switch();

src/common/platform/onboard/aicpu/device_log.cpp

@@ -24,11 +24,23 @@
 #include <cstdarg>
 #include <cstdio>
 
+namespace {
 bool g_is_log_enable_debug = false;
 bool g_is_log_enable_info = false;
 bool g_is_log_enable_timing = false;
 bool g_is_log_enable_warn = false;
 bool g_is_log_enable_error = false;
+}  // namespace
+
+bool is_log_enable_debug() { return g_is_log_enable_debug; }
+
+bool is_log_enable_info() { return g_is_log_enable_info; }
+
+bool is_log_enable_timing() { return g_is_log_enable_timing; }
+
+bool is_log_enable_warn() { return g_is_log_enable_warn; }
+
+bool is_log_enable_error() { return g_is_log_enable_error; }
 
 void init_log_switch() {
     g_is_log_enable_debug = CheckLogLevel(AICPU, DLOG_DEBUG);

src/common/platform/shared/aicpu/unified_log_device.cpp

@@ -13,11 +13,12 @@
  * @brief Unified logging - Device implementation.
  *
  * Forwards the unified C ABI to dev_vlog_* primitives via va_list — no
- * intermediate vsnprintf-to-buffer round-trip in this layer. On sim,
- * dev_vlog_* is a single vfprintf (buffer-free); on onboard, it still
- * buffers internally because CANN's dlog has no va_list variant.
+ * intermediate vsnprintf-to-buffer round-trip in this layer. Sim dev_vlog_*
+ * delegates to the bound HostLogger; onboard buffers internally because
+ * CANN's dlog has no va_list variant.
  *
- * Level flags come from device_log.cpp's globals (set at init time).
+ * Severity queries are platform-specific: sim reads the live bound threshold,
+ * while onboard reads the CANN-derived flags initialized by device_log.cpp.
  */
 
 #include "common/unified_log.h"