diff --git a/ROADMAP.md b/ROADMAP.md index b1ffbd50..93951300 100644 --- a/ROADMAP.md +++ b/ROADMAP.md @@ -252,68 +252,80 @@ Tests added: `tests/core/test_grid.c` with 16 unit tests. - `examples/*.c` - Example error handling - `README.md` - API documentation updates -### 0.6 Structured Logging & Diagnostics (P2) +### 0.6 Structured Logging & Diagnostics (P2) ✅ -**Status:** Partial - `cfd_set_log_callback()` API exists but not used consistently +**Status:** Complete -**Current Issues:** +**Implementation Tasks:** -- Raw `fprintf(stderr, ...)` and `snprintf()` scattered throughout codebase -- No log levels (can't filter INFO vs WARNING vs ERROR) -- No redirection (always stderr, can't send to file/syslog/GUI) -- No timestamps or structured metadata -- Not thread-safe (garbled output from multiple threads) -- Mixed purposes (diagnostics vs error messages) +- [x] Define `cfd_log()` API with log levels and component tags +- [x] Implement default console handler (stderr for WARNING/ERROR, stdout for DEBUG/INFO) +- [x] Add thread-safe logging (atomic global log level, per-thread callbacks) +- [x] Replace all `fprintf(stderr, ...)` calls with `cfd_log()` +- [x] Replace diagnostic `printf()` calls with `cfd_log()` +- [x] Add log filtering by level (suppress DEBUG in production) +- [x] Support custom log handlers via `cfd_set_log_callback_ex()` (with component) +- [ ] Add log filtering by component (e.g., only show "boundary" logs) — deferred +- [ ] Add timestamps and colored output — deferred +- [ ] Add structured data API for metrics (convergence stats, timings) — deferred -**Proposed Structured Logging API:** +**API added:** ```c -// Log levels +// Log levels (renumbered to include DEBUG) typedef enum { - CFD_LOG_DEBUG = 0, - CFD_LOG_INFO = 1, - CFD_LOG_WARNING = 2, - CFD_LOG_ERROR = 3 + CFD_LOG_LEVEL_DEBUG = 0, + CFD_LOG_LEVEL_INFO = 1, + CFD_LOG_LEVEL_WARNING = 2, + CFD_LOG_LEVEL_ERROR = 3 } cfd_log_level_t; -// Logging function with structured metadata +// Core logging function with printf-style formatting void cfd_log(cfd_log_level_t level, const char* component, - const char* format, ...); - -// Example usage -cfd_log(CFD_LOG_WARNING, "poisson_solver", - "Failed to converge (grid %zux%zu, dt=%.4e)", - nx, ny, dt); + const char* fmt, ...); + +// Global log level control (atomic, thread-safe) +void cfd_set_log_level(cfd_log_level_t level); +cfd_log_level_t cfd_get_log_level(void); + +// Extended callback with component tag +typedef void (*cfd_log_callback_ex_t)(cfd_log_level_t level, + const char* component, const char* message); +void cfd_set_log_callback_ex(cfd_log_callback_ex_t callback); + +// Convenience macros +CFD_LOG_DEBUG(component, ...) +CFD_LOG_INFO(component, ...) +CFD_LOG_WARNING(component, ...) +CFD_LOG_ERROR(component, ...) ``` -**Implementation Tasks:** - -- [ ] Define `cfd_log()` API with log levels and component tags -- [ ] Implement default console handler (with timestamps, colored output) -- [ ] Add thread-safe logging (mutex-protected or per-thread buffers) -- [ ] Replace all `fprintf(stderr, ...)` calls with `cfd_log()` -- [ ] Replace diagnostic `snprintf()` with `cfd_log()` where appropriate -- [ ] Add log filtering by level (suppress DEBUG in production) -- [ ] Add log filtering by component (e.g., only show "boundary" logs) -- [ ] Support custom log handlers via callback -- [ ] Add structured data API for metrics (convergence stats, timings) +**Design decisions:** -**Benefits:** - -- Users can redirect logs to files, syslog, or application UI -- Fine-grained control (enable DEBUG for specific components) -- Better debugging (timestamps, thread IDs, component context) -- Thread-safe by design -- Statistics aggregation ("Poisson failed 15 times this run") -- Can mute logs entirely for embedded/production use +- Default log level is INFO (DEBUG suppressed unless explicitly enabled) +- Per-thread legacy callback takes priority over global extended callback +- `cfd_error()` always sets thread-local error state regardless of log level filter +- Convergence verbose output uses `CFD_LOG_DEBUG` with `if (params->verbose)` guard +- Component tags: "gpu", "boundary", "poisson", "projection", "solver", "simd" +- Default output format: `LEVEL [component]: message` -**Files to Modify:** +**Files modified:** -- `lib/src/solvers/linear/cpu/linear_solver_*.c` - Replace fprintf -- `lib/src/solvers/navier_stokes/cpu/solver_*.c` - Replace fprintf -- `lib/src/solvers/navier_stokes/omp/solver_*.c` - Replace fprintf -- `lib/src/solvers/navier_stokes/avx2/solver_*.c` - Replace fprintf -- `tests/validation/lid_driven_cavity_common.h` - Replace snprintf for diagnostics +- `lib/include/cfd/core/logging.h` — Extended API with DEBUG level, `cfd_log()`, macros +- `lib/src/core/logging.c` — `cfd_log()` implementation, atomic log level, extended callback +- `lib/src/api/solver_registry.c` — 5 fprintf → CFD_LOG_ERROR/WARNING +- `lib/src/boundary/boundary_conditions.c` — 1 fprintf → CFD_LOG_ERROR +- `lib/src/solvers/linear/linear_solver.c` — 2 fprintf/printf → CFD_LOG_ERROR/DEBUG +- `lib/src/solvers/linear/simd/linear_solver_simd_dispatch.c` — 1 fprintf → CFD_LOG_DEBUG +- `lib/src/solvers/linear/cpu/linear_solver_cg.c` — 1 printf → CFD_LOG_DEBUG +- `lib/src/solvers/linear/cpu/linear_solver_bicgstab.c` — 1 printf → CFD_LOG_DEBUG +- `lib/src/solvers/linear/avx2/linear_solver_cg_avx2.c` — 1 printf → CFD_LOG_DEBUG +- `lib/src/solvers/linear/neon/linear_solver_cg_neon.c` — 1 printf → CFD_LOG_DEBUG +- `lib/src/solvers/linear/omp/linear_solver_cg_omp.c` — 1 printf → CFD_LOG_DEBUG +- `lib/src/solvers/navier_stokes/avx2/solver_explicit_euler_avx2.c` — 4 printf → CFD_LOG_INFO +- `lib/src/solvers/navier_stokes/avx2/solver_projection_avx2.c` — 1 fprintf → CFD_LOG_WARNING +- `lib/src/solvers/navier_stokes/avx2/solver_rk2_avx2.c` — 2 printf → CFD_LOG_INFO +- `tests/core/test_logging.c` — 11 new tests (16 total) --- diff --git a/lib/include/cfd/core/logging.h b/lib/include/cfd/core/logging.h index d1952669..19943d10 100644 --- a/lib/include/cfd/core/logging.h +++ b/lib/include/cfd/core/logging.h @@ -3,27 +3,92 @@ #include "cfd/cfd_export.h" +/* Printf format checking attribute */ +#if defined(__GNUC__) || defined(__clang__) +#define CFD_PRINTF_FORMAT(fmt_idx, arg_idx) __attribute__((format(printf, fmt_idx, arg_idx))) +#else +#define CFD_PRINTF_FORMAT(fmt_idx, arg_idx) +#endif + #ifdef __cplusplus extern "C" { #endif -// Log levels -typedef enum { CFD_LOG_LEVEL_INFO, CFD_LOG_LEVEL_WARNING, CFD_LOG_LEVEL_ERROR } cfd_log_level_t; +/* ============================================================================ + * LOG LEVELS + * ============================================================================ */ + +typedef enum { + CFD_LOG_LEVEL_DEBUG = 0, + CFD_LOG_LEVEL_INFO = 1, + CFD_LOG_LEVEL_WARNING = 2, + CFD_LOG_LEVEL_ERROR = 3 +} cfd_log_level_t; + +/* ============================================================================ + * CALLBACK TYPES + * ============================================================================ */ -// Log callback function type +/** Per-thread callback (legacy — no component info) */ typedef void (*cfd_log_callback_t)(cfd_log_level_t level, const char* message); -// Set a custom logging callback for the CURRENT THREAD (pass NULL to reset to default stderr -// output) +/** Extended callback with component tag */ +typedef void (*cfd_log_callback_ex_t)(cfd_log_level_t level, const char* component, + const char* message); + +/* ============================================================================ + * CORE LOGGING API + * ============================================================================ */ + +/** + * Log a message with printf-style formatting, a log level, and a component tag. + * + * Messages below the global log level are suppressed (fast atomic check). + * + * Dispatch priority: + * 1. Per-thread callback (set via cfd_set_log_callback) + * 2. Global extended callback (set via cfd_set_log_callback_ex) + * 3. Default handler (stderr for WARNING/ERROR, stdout for DEBUG/INFO) + * + * @param level Log level (DEBUG, INFO, WARNING, ERROR) + * @param component Component tag (e.g., "poisson", "boundary") or NULL + * @param fmt printf-style format string + */ +CFD_LIBRARY_EXPORT void cfd_log(cfd_log_level_t level, const char* component, const char* fmt, + ...) CFD_PRINTF_FORMAT(3, 4); + +/** Set the global minimum log level (default: CFD_LOG_LEVEL_INFO). Thread-safe. */ +CFD_LIBRARY_EXPORT void cfd_set_log_level(cfd_log_level_t level); + +/** Get the current global minimum log level. Thread-safe. */ +CFD_LIBRARY_EXPORT cfd_log_level_t cfd_get_log_level(void); + +/** Set a global extended callback (receives component info). Pass NULL to reset. */ +CFD_LIBRARY_EXPORT void cfd_set_log_callback_ex(cfd_log_callback_ex_t callback); + +/* ============================================================================ + * CONVENIENCE MACROS + * ============================================================================ */ + +#define CFD_LOG_DEBUG(component, ...) cfd_log(CFD_LOG_LEVEL_DEBUG, (component), __VA_ARGS__) +#define CFD_LOG_INFO(component, ...) cfd_log(CFD_LOG_LEVEL_INFO, (component), __VA_ARGS__) +#define CFD_LOG_WARNING(component, ...) cfd_log(CFD_LOG_LEVEL_WARNING, (component), __VA_ARGS__) +#define CFD_LOG_ERROR(component, ...) cfd_log(CFD_LOG_LEVEL_ERROR, (component), __VA_ARGS__) + +/* ============================================================================ + * LEGACY API (backward-compatible convenience wrappers) + * ============================================================================ */ + +/** Set a per-thread logging callback (pass NULL to reset to default stderr output) */ CFD_LIBRARY_EXPORT void cfd_set_log_callback(cfd_log_callback_t callback); -// Log error message and set thread-local error state (does NOT exit) +/** Log error message and set thread-local error state (does NOT exit) */ CFD_LIBRARY_EXPORT void cfd_error(const char* message); -// Print warning message +/** Print warning message */ CFD_LIBRARY_EXPORT void cfd_warning(const char* message); -// Print info message +/** Print info message */ CFD_LIBRARY_EXPORT void cfd_info(const char* message); #ifdef __cplusplus diff --git a/lib/src/api/solver_registry.c b/lib/src/api/solver_registry.c index c926ae20..f8cf2571 100644 --- a/lib/src/api/solver_registry.c +++ b/lib/src/api/solver_registry.c @@ -3,6 +3,7 @@ #include "cfd/core/filesystem.h" #include "cfd/core/gpu_device.h" #include "cfd/core/grid.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include "cfd/solvers/navier_stokes_solver.h" #include "cfd/solvers/poisson_solver.h" @@ -946,7 +947,7 @@ static cfd_status_t gpu_euler_init(ns_solver_t* solver, const grid* grid, const ctx->gpu_ctx = gpu_solver_create(grid->nx, grid->ny, grid->nz, &ctx->gpu_config_t); if (!ctx->gpu_ctx) { cfd_free(ctx); - fprintf(stderr, "GPU Euler init: Failed to create GPU context\n"); + CFD_LOG_ERROR("gpu", "GPU Euler init: Failed to create GPU context"); return CFD_ERROR_UNSUPPORTED; } } @@ -1006,13 +1007,13 @@ static cfd_status_t gpu_euler_step(ns_solver_t* solver, flow_field* field, const } } // GPU operation failed - fprintf(stderr, "GPU Euler step: GPU operation failed\n"); + CFD_LOG_ERROR("gpu", "GPU Euler step: GPU operation failed"); return CFD_ERROR_INVALID; } // GPU not available - could be: CUDA not compiled in, gpu_should_use() returned false, // or GPU initialization failed - fprintf(stderr, "GPU Euler step: GPU solver not initialized\n"); + CFD_LOG_ERROR("gpu", "GPU Euler step: GPU solver not initialized"); return CFD_ERROR_UNSUPPORTED; } @@ -1051,7 +1052,7 @@ static cfd_status_t gpu_euler_solve(ns_solver_t* solver, flow_field* field, cons // GPU not available - could be: CUDA not compiled in, gpu_should_use() returned false, // or GPU initialization failed - fprintf(stderr, "GPU Euler solve: GPU solver not initialized\n"); + CFD_LOG_ERROR("gpu", "GPU Euler solve: GPU solver not initialized"); return CFD_ERROR_UNSUPPORTED; } @@ -1335,7 +1336,7 @@ static cfd_status_t projection_omp_init(ns_solver_t* solver, const grid* grid, poisson_solver_t* test_solver = poisson_solver_create( POISSON_METHOD_CG, POISSON_BACKEND_OMP); if (!test_solver) { - fprintf(stderr, "projection_omp_init: OMP CG Poisson solver not available\n"); + CFD_LOG_WARNING("projection", "OMP CG Poisson solver not available"); return CFD_ERROR_UNSUPPORTED; } poisson_solver_destroy(test_solver); diff --git a/lib/src/boundary/boundary_conditions.c b/lib/src/boundary/boundary_conditions.c index 3b2b966d..1f031f31 100644 --- a/lib/src/boundary/boundary_conditions.c +++ b/lib/src/boundary/boundary_conditions.c @@ -38,7 +38,7 @@ static void default_error_handler(bc_error_code_t error_code, const char* message, void* user_data) { (void)user_data; /* Unused in default handler */ - fprintf(stderr, "BC ERROR [%d] in %s: %s\n", (int)error_code, function, message); + CFD_LOG_ERROR("boundary", "BC [%d] in %s: %s", (int)error_code, function, message); } void bc_set_error_handler(bc_error_handler_t handler, void* user_data) { diff --git a/lib/src/core/cfd_threading_internal.h b/lib/src/core/cfd_threading_internal.h index 75e72984..e515f33b 100644 --- a/lib/src/core/cfd_threading_internal.h +++ b/lib/src/core/cfd_threading_internal.h @@ -25,6 +25,17 @@ static inline void cfd_atomic_store(cfd_atomic_int* ptr, int value) { InterlockedExchange(ptr, value); } +/* Atomic pointer operations (for function pointer globals) */ +typedef void* volatile cfd_atomic_ptr; + +static inline void* cfd_atomic_ptr_load(const cfd_atomic_ptr* ptr) { + return InterlockedCompareExchangePointer((volatile PVOID*)ptr, NULL, NULL); +} + +static inline void cfd_atomic_ptr_store(cfd_atomic_ptr* ptr, void* value) { + InterlockedExchangePointer(ptr, value); +} + #else #include @@ -44,6 +55,20 @@ static inline void cfd_atomic_store(cfd_atomic_int* ptr, int value) { atomic_store(ptr, value); } +/* Atomic pointer operations (for function pointer globals). + * Uses uintptr_t to avoid _Atomic(void*) which can cause TSan issues. */ +#include + +typedef _Atomic(uintptr_t) cfd_atomic_ptr; + +static inline void* cfd_atomic_ptr_load(cfd_atomic_ptr* ptr) { + return (void*)atomic_load(ptr); +} + +static inline void cfd_atomic_ptr_store(cfd_atomic_ptr* ptr, void* value) { + atomic_store(ptr, (uintptr_t)value); +} + #endif #endif // CFD_THREADING_INTERNAL_H diff --git a/lib/src/core/logging.c b/lib/src/core/logging.c index 9dc94112..1011f5bc 100644 --- a/lib/src/core/logging.c +++ b/lib/src/core/logging.c @@ -1,22 +1,40 @@ #include "cfd/core/logging.h" #include "cfd/core/cfd_status.h" +#include "cfd_threading_internal.h" + +#include #include +/* ============================================================================ + * THREAD-LOCAL STATE + * ============================================================================ */ #ifdef _WIN32 static __declspec(thread) cfd_status_t g_last_status = CFD_SUCCESS; static __declspec(thread) char g_last_error_msg[256] = {0}; static __declspec(thread) cfd_log_callback_t s_log_callback = NULL; #else -#include static __thread cfd_status_t g_last_status = CFD_SUCCESS; static __thread char g_last_error_msg[256] = {0}; static __thread cfd_log_callback_t s_log_callback = NULL; #endif -//============================================================================= -// ERROR CONTEXT -//============================================================================= +/* ============================================================================ + * GLOBAL STATE + * ============================================================================ */ + +/* Default log level: INFO (suppresses DEBUG) */ +static cfd_atomic_int s_global_log_level = CFD_LOG_LEVEL_INFO; + +/* Global extended callback (set once at startup, read on every log call) */ +static cfd_atomic_ptr s_global_callback_ex; + +/* Level name table (const, thread-safe) */ +static const char* const s_level_names[] = {"DEBUG", "INFO", "WARNING", "ERROR"}; + +/* ============================================================================ + * ERROR CONTEXT + * ============================================================================ */ void cfd_set_error(cfd_status_t status, const char* message) { g_last_status = status; @@ -70,9 +88,76 @@ void cfd_clear_error(void) { g_last_error_msg[0] = '\0'; } -//============================================================================= -// LOGGING -//============================================================================= +/* ============================================================================ + * CORE LOGGING + * ============================================================================ */ + +void cfd_log(cfd_log_level_t level, const char* component, const char* fmt, ...) { + /* Fast path: suppress messages below global log level */ + if ((int)level < cfd_atomic_load(&s_global_log_level)) { + return; + } + + /* Format message on stack */ + char buf[512]; + va_list args; + va_start(args, fmt); + vsnprintf(buf, sizeof(buf), fmt, args); + va_end(args); + + /* Dispatch: per-thread callback > global extended callback > default handler */ + if (s_log_callback) { + s_log_callback(level, buf); + return; + } + + cfd_log_callback_ex_t cb_ex = + (cfd_log_callback_ex_t)cfd_atomic_ptr_load(&s_global_callback_ex); + if (cb_ex) { + cb_ex(level, component, buf); + } else { + const char* level_str = + ((int)level >= 0 && (int)level <= 3) ? s_level_names[(int)level] : "UNKNOWN"; + FILE* stream = (level >= CFD_LOG_LEVEL_WARNING) ? stderr : stdout; + if (component) { + fprintf(stream, "%s [%s]: %s\n", level_str, component, buf); + } else { + fprintf(stream, "%s: %s\n", level_str, buf); + } + } +} + +void cfd_set_log_level(cfd_log_level_t level) { + int lvl = (int)level; + + if (lvl < (int)CFD_LOG_LEVEL_DEBUG) { + lvl = (int)CFD_LOG_LEVEL_DEBUG; + } else if (lvl > (int)CFD_LOG_LEVEL_ERROR) { + lvl = (int)CFD_LOG_LEVEL_ERROR; + } + + cfd_atomic_store(&s_global_log_level, lvl); +} + +cfd_log_level_t cfd_get_log_level(void) { + int lvl = cfd_atomic_load(&s_global_log_level); + + if (lvl < (int)CFD_LOG_LEVEL_DEBUG) { + lvl = (int)CFD_LOG_LEVEL_DEBUG; + } else if (lvl > (int)CFD_LOG_LEVEL_ERROR) { + lvl = (int)CFD_LOG_LEVEL_ERROR; + } + + return (cfd_log_level_t)lvl; +} + +void cfd_set_log_callback_ex(cfd_log_callback_ex_t callback) { + cfd_atomic_ptr_store(&s_global_callback_ex, (void*)callback); +} + +/* ============================================================================ + * LEGACY API + * ============================================================================ */ void cfd_set_log_callback(cfd_log_callback_t callback) { s_log_callback = callback; @@ -80,28 +165,17 @@ void cfd_set_log_callback(cfd_log_callback_t callback) { void cfd_error(const char* message) { const char* safe_msg = message ? message : "(null)"; - if (s_log_callback) { - s_log_callback(CFD_LOG_LEVEL_ERROR, safe_msg); - } else { - fprintf(stderr, "ERROR: %s\n", safe_msg); - } + /* Always set error state, regardless of log level filter */ cfd_set_error(CFD_ERROR, safe_msg); + cfd_log(CFD_LOG_LEVEL_ERROR, NULL, "%s", safe_msg); } void cfd_warning(const char* message) { const char* safe_msg = message ? message : "(null)"; - if (s_log_callback) { - s_log_callback(CFD_LOG_LEVEL_WARNING, safe_msg); - } else { - fprintf(stderr, "WARNING: %s\n", safe_msg); - } + cfd_log(CFD_LOG_LEVEL_WARNING, NULL, "%s", safe_msg); } void cfd_info(const char* message) { const char* safe_msg = message ? message : "(null)"; - if (s_log_callback) { - s_log_callback(CFD_LOG_LEVEL_INFO, safe_msg); - } else { - fprintf(stdout, "INFO: %s\n", safe_msg); - } + cfd_log(CFD_LOG_LEVEL_INFO, NULL, "%s", safe_msg); } diff --git a/lib/src/solvers/linear/avx2/linear_solver_cg_avx2.c b/lib/src/solvers/linear/avx2/linear_solver_cg_avx2.c index 09c40087..a3a141df 100644 --- a/lib/src/solvers/linear/avx2/linear_solver_cg_avx2.c +++ b/lib/src/solvers/linear/avx2/linear_solver_cg_avx2.c @@ -19,6 +19,7 @@ #include "cfd/boundary/boundary_conditions.h" #include "cfd/core/cpu_features.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include @@ -596,7 +597,7 @@ static cfd_status_t cg_avx2_solve( /* Check convergence at intervals */ if (iter % params->check_interval == 0) { if (params->verbose) { - printf(" CG AVX2 Iter %d: residual = %.6e\n", iter, res_norm); + CFD_LOG_DEBUG("poisson", "CG AVX2 Iter %d: residual = %.6e", iter, res_norm); } if (res_norm < tolerance || res_norm < params->absolute_tolerance) { diff --git a/lib/src/solvers/linear/cpu/linear_solver_bicgstab.c b/lib/src/solvers/linear/cpu/linear_solver_bicgstab.c index 2dc690cc..ac15ff78 100644 --- a/lib/src/solvers/linear/cpu/linear_solver_bicgstab.c +++ b/lib/src/solvers/linear/cpu/linear_solver_bicgstab.c @@ -38,10 +38,10 @@ #include "../linear_solver_internal.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include -#include #include /* ============================================================================ @@ -453,7 +453,7 @@ static cfd_status_t bicgstab_scalar_solve( /* Check convergence at intervals */ if (iter % params->check_interval == 0) { if (params->verbose) { - printf(" BiCGSTAB Iter %d: residual = %.6e\n", iter, res_norm); + CFD_LOG_DEBUG("poisson", "BiCGSTAB Iter %d: residual = %.6e", iter, res_norm); } if (res_norm < tolerance || res_norm < params->absolute_tolerance) { diff --git a/lib/src/solvers/linear/cpu/linear_solver_cg.c b/lib/src/solvers/linear/cpu/linear_solver_cg.c index 1e6c1bee..0afc0033 100644 --- a/lib/src/solvers/linear/cpu/linear_solver_cg.c +++ b/lib/src/solvers/linear/cpu/linear_solver_cg.c @@ -27,10 +27,10 @@ #include "../linear_solver_internal.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include -#include #include /* ============================================================================ @@ -399,7 +399,7 @@ static cfd_status_t cg_scalar_solve( /* Check convergence at intervals */ if (iter % params->check_interval == 0) { if (params->verbose) { - printf(" CG Iter %d: residual = %.6e\n", iter, res_norm); + CFD_LOG_DEBUG("poisson", "CG Iter %d: residual = %.6e", iter, res_norm); } if (res_norm < tolerance || res_norm < params->absolute_tolerance) { diff --git a/lib/src/solvers/linear/linear_solver.c b/lib/src/solvers/linear/linear_solver.c index 1d23a40d..8b732696 100644 --- a/lib/src/solvers/linear/linear_solver.c +++ b/lib/src/solvers/linear/linear_solver.c @@ -15,6 +15,7 @@ #include "cfd/boundary/boundary_conditions.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include @@ -432,7 +433,7 @@ cfd_status_t poisson_solver_solve_common( res = new_res; if (params->verbose) { - printf(" Iter %d: residual = %.6e\n", iter, res); + CFD_LOG_DEBUG("poisson", "Iter %d: residual = %.6e", iter, res); } if (res < tolerance || res < params->absolute_tolerance) { @@ -622,7 +623,7 @@ int poisson_solve_3d( break; default: - fprintf(stderr, "poisson_solve_3d: Unknown solver type %d\n", solver_type); + CFD_LOG_ERROR("poisson", "poisson_solve_3d: Unknown solver type %d", solver_type); return -1; } diff --git a/lib/src/solvers/linear/neon/linear_solver_cg_neon.c b/lib/src/solvers/linear/neon/linear_solver_cg_neon.c index 99f9a873..b04543cd 100644 --- a/lib/src/solvers/linear/neon/linear_solver_cg_neon.c +++ b/lib/src/solvers/linear/neon/linear_solver_cg_neon.c @@ -19,6 +19,7 @@ #include "cfd/boundary/boundary_conditions.h" #include "cfd/core/cpu_features.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include @@ -591,7 +592,7 @@ static cfd_status_t cg_neon_solve( /* Check convergence at intervals */ if (iter % params->check_interval == 0) { if (params->verbose) { - printf(" CG NEON Iter %d: residual = %.6e\n", iter, res_norm); + CFD_LOG_DEBUG("poisson", "CG NEON Iter %d: residual = %.6e", iter, res_norm); } if (res_norm < tolerance || res_norm < params->absolute_tolerance) { diff --git a/lib/src/solvers/linear/omp/linear_solver_cg_omp.c b/lib/src/solvers/linear/omp/linear_solver_cg_omp.c index 1168471e..3b340afd 100644 --- a/lib/src/solvers/linear/omp/linear_solver_cg_omp.c +++ b/lib/src/solvers/linear/omp/linear_solver_cg_omp.c @@ -9,10 +9,10 @@ #include "../linear_solver_internal.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include -#include #include #ifdef CFD_ENABLE_OPENMP @@ -357,7 +357,7 @@ static cfd_status_t cg_omp_solve( if (iter % params->check_interval == 0) { if (params->verbose) { - printf(" CG-OMP Iter %d: residual = %.6e\n", iter, res_norm); + CFD_LOG_DEBUG("poisson", "CG-OMP Iter %d: residual = %.6e", iter, res_norm); } if (res_norm < tolerance || res_norm < params->absolute_tolerance) { diff --git a/lib/src/solvers/linear/simd/linear_solver_simd_dispatch.c b/lib/src/solvers/linear/simd/linear_solver_simd_dispatch.c index a937d585..25668320 100644 --- a/lib/src/solvers/linear/simd/linear_solver_simd_dispatch.c +++ b/lib/src/solvers/linear/simd/linear_solver_simd_dispatch.c @@ -20,8 +20,7 @@ #include "../linear_solver_internal.h" #include "cfd/core/cpu_features.h" - -#include +#include "cfd/core/logging.h" /* ============================================================================ * LOGGING @@ -32,15 +31,8 @@ * Callers should handle the NULL return and fall back to scalar if needed. */ static void log_no_simd_available(const char* solver_type) { - /* Silent in release builds - caller handles fallback */ -#ifdef CFD_DEBUG - fprintf(stderr, - "DEBUG: SIMD %s solver not available " - "(detected arch: %s). Returning NULL for fallback.\n", - solver_type, cfd_get_simd_name()); -#else - (void)solver_type; /* Suppress unused parameter warning */ -#endif + CFD_LOG_DEBUG("simd", "SIMD %s solver not available (detected arch: %s). " + "Returning NULL for fallback.", solver_type, cfd_get_simd_name()); } /* ============================================================================ diff --git a/lib/src/solvers/navier_stokes/avx2/solver_explicit_euler_avx2.c b/lib/src/solvers/navier_stokes/avx2/solver_explicit_euler_avx2.c index 6b7e1f5e..ca943753 100644 --- a/lib/src/solvers/navier_stokes/avx2/solver_explicit_euler_avx2.c +++ b/lib/src/solvers/navier_stokes/avx2/solver_explicit_euler_avx2.c @@ -20,6 +20,7 @@ #include "cfd/core/cfd_status.h" #include "cfd/core/grid.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include "cfd/solvers/navier_stokes_solver.h" @@ -164,15 +165,15 @@ cfd_status_t explicit_euler_simd_init(struct NSSolver* solver, const grid* grid, #if USE_AVX #ifdef _OPENMP - printf("Explicit Euler SIMD: AVX2 + OpenMP enabled (%d threads)\n", omp_get_max_threads()); + CFD_LOG_INFO("solver", "Explicit Euler SIMD: AVX2 + OpenMP enabled (%d threads)", omp_get_max_threads()); #else - printf("Explicit Euler SIMD: AVX2 enabled (OpenMP disabled)\n"); + CFD_LOG_INFO("solver", "Explicit Euler SIMD: AVX2 enabled (OpenMP disabled)"); #endif #else #ifdef _OPENMP - printf("Explicit Euler OMP: Scalar + OpenMP enabled (%d threads)\n", omp_get_max_threads()); + CFD_LOG_INFO("solver", "Explicit Euler OMP: Scalar + OpenMP enabled (%d threads)", omp_get_max_threads()); #else - printf("Explicit Euler: Scalar fallback (no SIMD or OpenMP)\n"); + CFD_LOG_INFO("solver", "Explicit Euler: Scalar fallback (no SIMD or OpenMP)"); #endif #endif diff --git a/lib/src/solvers/navier_stokes/avx2/solver_projection_avx2.c b/lib/src/solvers/navier_stokes/avx2/solver_projection_avx2.c index 0eb883b4..df0da98d 100644 --- a/lib/src/solvers/navier_stokes/avx2/solver_projection_avx2.c +++ b/lib/src/solvers/navier_stokes/avx2/solver_projection_avx2.c @@ -13,6 +13,7 @@ #include "cfd/core/cfd_status.h" #include "cfd/core/grid.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include "cfd/solvers/navier_stokes_solver.h" #include "cfd/solvers/poisson_solver.h" @@ -85,7 +86,7 @@ cfd_status_t projection_simd_init(struct NSSolver* solver, const grid* grid, poisson_solver_t* test_solver = poisson_solver_create( POISSON_METHOD_CG, POISSON_BACKEND_SIMD); if (!test_solver) { - fprintf(stderr, "projection_simd_init: SIMD CG Poisson solver not available\n"); + CFD_LOG_WARNING("projection", "SIMD CG Poisson solver not available"); return CFD_ERROR_UNSUPPORTED; } poisson_solver_destroy(test_solver); diff --git a/lib/src/solvers/navier_stokes/avx2/solver_rk2_avx2.c b/lib/src/solvers/navier_stokes/avx2/solver_rk2_avx2.c index ed997b4c..dfbb64b8 100644 --- a/lib/src/solvers/navier_stokes/avx2/solver_rk2_avx2.c +++ b/lib/src/solvers/navier_stokes/avx2/solver_rk2_avx2.c @@ -29,6 +29,7 @@ #include "cfd/core/cfd_status.h" #include "cfd/core/grid.h" #include "cfd/core/indexing.h" +#include "cfd/core/logging.h" #include "cfd/core/memory.h" #include "cfd/solvers/navier_stokes_solver.h" @@ -729,9 +730,9 @@ cfd_status_t rk2_avx2_init(ns_solver_t* solver, const grid* g, solver->context = ctx; #ifdef _OPENMP - printf("RK2 SIMD: AVX2 + OpenMP enabled (%d threads)\n", omp_get_max_threads()); + CFD_LOG_INFO("solver", "RK2 SIMD: AVX2 + OpenMP enabled (%d threads)", omp_get_max_threads()); #else - printf("RK2 SIMD: AVX2 enabled (OpenMP disabled)\n"); + CFD_LOG_INFO("solver", "RK2 SIMD: AVX2 enabled (OpenMP disabled)"); #endif return CFD_SUCCESS; diff --git a/tests/core/test_logging.c b/tests/core/test_logging.c index 3a014e15..f0002fdb 100644 --- a/tests/core/test_logging.c +++ b/tests/core/test_logging.c @@ -1,26 +1,44 @@ #include "cfd/core/cfd_status.h" #include "cfd/core/logging.h" #include "unity.h" +#include #include -// Mock callback state +// Mock callback state (legacy per-thread callback) static int s_callback_called = 0; static cfd_log_level_t s_last_level; static char s_last_message[256]; +// Mock extended callback state +static int s_ex_callback_called = 0; +static cfd_log_level_t s_ex_last_level; +static char s_ex_last_component[64]; +static char s_ex_last_message[256]; + void setUp(void) { s_callback_called = 0; - s_last_level = -1; + s_last_level = (cfd_log_level_t)-1; memset(s_last_message, 0, sizeof(s_last_message)); - cfd_set_log_callback(NULL); // Reset to default + + s_ex_callback_called = 0; + s_ex_last_level = (cfd_log_level_t)-1; + memset(s_ex_last_component, 0, sizeof(s_ex_last_component)); + memset(s_ex_last_message, 0, sizeof(s_ex_last_message)); + + cfd_set_log_callback(NULL); + cfd_set_log_callback_ex(NULL); + cfd_set_log_level(CFD_LOG_LEVEL_INFO); // Reset to default + cfd_clear_error(); } void tearDown(void) { cfd_set_log_callback(NULL); + cfd_set_log_callback_ex(NULL); + cfd_set_log_level(CFD_LOG_LEVEL_INFO); } -// Mock callback function +// Mock callback function (legacy) void mock_log_callback(cfd_log_level_t level, const char* message) { s_callback_called++; s_last_level = level; @@ -29,6 +47,26 @@ void mock_log_callback(cfd_log_level_t level, const char* message) { } } +// Mock extended callback function +void mock_log_callback_ex(cfd_log_level_t level, const char* component, const char* message) { + s_ex_callback_called++; + s_ex_last_level = level; + if (component) { + snprintf(s_ex_last_component, sizeof(s_ex_last_component), "%s", component); + } else { + s_ex_last_component[0] = '\0'; + } + if (message) { + snprintf(s_ex_last_message, sizeof(s_ex_last_message), "%s", message); + } else { + s_ex_last_message[0] = '\0'; + } +} + +/* ============================================================================ + * LEGACY API TESTS (backward compatibility) + * ============================================================================ */ + void test_error_logging_callback(void) { cfd_set_log_callback(mock_log_callback); @@ -93,12 +131,188 @@ void test_callback_reset(void) { TEST_ASSERT_EQUAL_INT(1, s_callback_called); } +/* ============================================================================ + * cfd_log() TESTS + * ============================================================================ */ + +void test_cfd_log_basic(void) { + cfd_set_log_callback(mock_log_callback); + + cfd_log(CFD_LOG_LEVEL_WARNING, "test", "hello %s", "world"); + + TEST_ASSERT_EQUAL_INT(1, s_callback_called); + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_WARNING, s_last_level); + TEST_ASSERT_EQUAL_STRING("hello world", s_last_message); +} + +void test_cfd_log_formatting(void) { + cfd_set_log_callback(mock_log_callback); + + cfd_log(CFD_LOG_LEVEL_INFO, "solver", "iter=%d residual=%.2e grid=%zux%zu", 42, 1.5e-6, + (size_t)33, (size_t)33); + + TEST_ASSERT_EQUAL_INT(1, s_callback_called); + TEST_ASSERT_EQUAL_STRING("iter=42 residual=1.50e-06 grid=33x33", s_last_message); +} + +void test_cfd_log_null_component(void) { + cfd_set_log_callback(mock_log_callback); + + cfd_log(CFD_LOG_LEVEL_INFO, NULL, "no component"); + + TEST_ASSERT_EQUAL_INT(1, s_callback_called); + TEST_ASSERT_EQUAL_STRING("no component", s_last_message); +} + +/* ============================================================================ + * LOG LEVEL FILTERING TESTS + * ============================================================================ */ + +void test_log_level_default_suppresses_debug(void) { + cfd_set_log_callback(mock_log_callback); + + // Default level is INFO, so DEBUG should be suppressed + CFD_LOG_DEBUG("test", "should not appear"); + TEST_ASSERT_EQUAL_INT(0, s_callback_called); + + // INFO should pass + CFD_LOG_INFO("test", "should appear"); + TEST_ASSERT_EQUAL_INT(1, s_callback_called); +} + +void test_log_level_filtering_suppresses(void) { + cfd_set_log_callback(mock_log_callback); + cfd_set_log_level(CFD_LOG_LEVEL_WARNING); + + // DEBUG and INFO should be suppressed + cfd_log(CFD_LOG_LEVEL_DEBUG, "test", "debug msg"); + TEST_ASSERT_EQUAL_INT(0, s_callback_called); + + cfd_log(CFD_LOG_LEVEL_INFO, "test", "info msg"); + TEST_ASSERT_EQUAL_INT(0, s_callback_called); +} + +void test_log_level_filtering_passes(void) { + cfd_set_log_callback(mock_log_callback); + cfd_set_log_level(CFD_LOG_LEVEL_WARNING); + + // WARNING and ERROR should pass + cfd_log(CFD_LOG_LEVEL_WARNING, "test", "warn msg"); + TEST_ASSERT_EQUAL_INT(1, s_callback_called); + + cfd_log(CFD_LOG_LEVEL_ERROR, "test", "error msg"); + TEST_ASSERT_EQUAL_INT(2, s_callback_called); +} + +void test_log_level_get_set(void) { + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_INFO, cfd_get_log_level()); + + cfd_set_log_level(CFD_LOG_LEVEL_DEBUG); + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_DEBUG, cfd_get_log_level()); + + cfd_set_log_level(CFD_LOG_LEVEL_ERROR); + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_ERROR, cfd_get_log_level()); +} + +/* ============================================================================ + * EXTENDED CALLBACK TESTS + * ============================================================================ */ + +void test_extended_callback(void) { + cfd_set_log_callback_ex(mock_log_callback_ex); + + cfd_log(CFD_LOG_LEVEL_INFO, "mycomp", "test message"); + + TEST_ASSERT_EQUAL_INT(1, s_ex_callback_called); + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_INFO, s_ex_last_level); + TEST_ASSERT_EQUAL_STRING("mycomp", s_ex_last_component); + TEST_ASSERT_EQUAL_STRING("test message", s_ex_last_message); +} + +void test_per_thread_callback_takes_priority(void) { + cfd_set_log_callback(mock_log_callback); + cfd_set_log_callback_ex(mock_log_callback_ex); + + cfd_log(CFD_LOG_LEVEL_INFO, "comp", "msg"); + + // Per-thread callback should be called, NOT extended + TEST_ASSERT_EQUAL_INT(1, s_callback_called); + TEST_ASSERT_EQUAL_INT(0, s_ex_callback_called); + + // Clear per-thread callback — extended should now be called + cfd_set_log_callback(NULL); + cfd_log(CFD_LOG_LEVEL_INFO, "comp", "msg2"); + + TEST_ASSERT_EQUAL_INT(1, s_callback_called); // unchanged + TEST_ASSERT_EQUAL_INT(1, s_ex_callback_called); + TEST_ASSERT_EQUAL_STRING("msg2", s_ex_last_message); +} + +/* ============================================================================ + * ERROR STATE PRESERVATION TESTS + * ============================================================================ */ + +void test_cfd_error_preserves_error_state(void) { + cfd_set_log_callback(mock_log_callback); + + cfd_error("test error"); + + TEST_ASSERT_EQUAL_INT(CFD_ERROR, cfd_get_last_status()); + TEST_ASSERT_EQUAL_STRING("test error", cfd_get_last_error()); +} + +/* ============================================================================ + * CONVENIENCE MACRO TESTS + * ============================================================================ */ + +void test_convenience_macros(void) { + cfd_set_log_callback(mock_log_callback); + + CFD_LOG_ERROR("comp", "val=%d", 42); + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_ERROR, s_last_level); + TEST_ASSERT_EQUAL_STRING("val=42", s_last_message); + + CFD_LOG_WARNING("comp", "warn"); + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_WARNING, s_last_level); + + CFD_LOG_INFO("comp", "info"); + TEST_ASSERT_EQUAL_INT(CFD_LOG_LEVEL_INFO, s_last_level); +} + +/* ============================================================================ + * MAIN + * ============================================================================ */ + int main(void) { UNITY_BEGIN(); + + // Legacy API tests RUN_TEST(test_error_logging_callback); RUN_TEST(test_warning_logging_callback); RUN_TEST(test_info_logging_callback); RUN_TEST(test_null_handling); RUN_TEST(test_callback_reset); + + // cfd_log() tests + RUN_TEST(test_cfd_log_basic); + RUN_TEST(test_cfd_log_formatting); + RUN_TEST(test_cfd_log_null_component); + + // Log level filtering tests + RUN_TEST(test_log_level_default_suppresses_debug); + RUN_TEST(test_log_level_filtering_suppresses); + RUN_TEST(test_log_level_filtering_passes); + RUN_TEST(test_log_level_get_set); + + // Extended callback tests + RUN_TEST(test_extended_callback); + RUN_TEST(test_per_thread_callback_takes_priority); + + // Error state preservation + RUN_TEST(test_cfd_error_preserves_error_state); + + // Convenience macros + RUN_TEST(test_convenience_macros); + return UNITY_END(); }