From 829a68c22a558df9e3577cbdb71794acda3bd272 Mon Sep 17 00:00:00 2001 From: "Tomwang.eth" <73059070+tomwangcn@users.noreply.github.com> Date: Sat, 7 Nov 2026 20:26:21 +0000 Subject: [PATCH] fix: keep llama.cpp logs routed to the latest logger after recreating `Llama` Creating a new `Llama` instance released the previous logger's thread-safe function before installing the new one. The old function's deferred finalizer then cleared the global logger callback flag, so native llama.cpp log lines stopped reaching the custom logger of the new instance and were printed to the process stdout instead. Install the new logger before releasing the previous one, and only clear the callback flag when the finalized logger is still the current one. Closes: #684 --- llama/addon/globals/addonLog.cpp | 28 +++++++++++++---- test/modelDependent/llama/logger.test.ts | 38 ++++++++++++++++++++++++ 2 files changed, 60 insertions(+), 6 deletions(-) create mode 100644 test/modelDependent/llama/logger.test.ts diff --git a/llama/addon/globals/addonLog.cpp b/llama/addon/globals/addonLog.cpp index 488bab1c..1d7eabb2 100644 --- a/llama/addon/globals/addonLog.cpp +++ b/llama/addon/globals/addonLog.cpp @@ -6,6 +6,7 @@ AddonThreadSafeLogCallbackFunction addonThreadSafeLoggerCallback; bool addonJsLoggerCallbackSet = false; +AddonThreadSafeLogCallbackFunctionContext* addonCurrentLoggerContext = nullptr; std::atomic addonLoggerLogLevel(5); std::atomic> addonLoggerLogLevelOverride(std::nullopt); std::atomic addonLastLoggerLogLevel(6); @@ -103,17 +104,26 @@ void addonLlamaCppLogCallback(ggml_log_level level, const char* text, void* user } Napi::Value setLogger(const Napi::CallbackInfo& info) { - if (addonJsLoggerCallbackSet) { - addonJsLoggerCallbackSet = false; - addonThreadSafeLoggerCallback.Release(); - } - if (info.Length() < 1 || !info[0].IsFunction()) { + if (addonJsLoggerCallbackSet) { + addonJsLoggerCallbackSet = false; + addonCurrentLoggerContext = nullptr; + addonThreadSafeLoggerCallback.Release(); + } + return info.Env().Undefined(); } auto addonLoggerJSCallback = info[0].As(); AddonThreadSafeLogCallbackFunctionContext* context = new Napi::Reference(Napi::Persistent(info.This())); + + // install the new logger before releasing the previous one, so that the previous logger's + // deferred finalizer cannot disable the new logger (the finalizer only disables logging + // when its context is still the current one) + const bool hadPreviousLogger = addonJsLoggerCallbackSet; + auto previousLoggerCallback = addonThreadSafeLoggerCallback; + + addonCurrentLoggerContext = context; addonThreadSafeLoggerCallback = AddonThreadSafeLogCallbackFunction::New( info.Env(), addonLoggerJSCallback, @@ -122,7 +132,10 @@ Napi::Value setLogger(const Napi::CallbackInfo& info) { 1, context, [](Napi::Env, void*, AddonThreadSafeLogCallbackFunctionContext* ctx) { - addonJsLoggerCallbackSet = false; + if (addonCurrentLoggerContext == ctx) { + addonJsLoggerCallbackSet = false; + addonCurrentLoggerContext = nullptr; + } delete ctx; } @@ -132,6 +145,9 @@ Napi::Value setLogger(const Napi::CallbackInfo& info) { // prevent blocking the main node process from exiting due to active resources addonThreadSafeLoggerCallback.Unref(info.Env()); + if (hadPreviousLogger) + previousLoggerCallback.Release(); + return info.Env().Undefined(); } diff --git a/test/modelDependent/llama/logger.test.ts b/test/modelDependent/llama/logger.test.ts new file mode 100644 index 00000000..d3161283 --- /dev/null +++ b/test/modelDependent/llama/logger.test.ts @@ -0,0 +1,38 @@ +import {describe, expect, test} from "vitest"; +import {getModelFile} from "../../utils/modelFiles.js"; +import {getLlama, LlamaLogLevel} from "../../../src/index.js"; + +describe("llama", () => { + describe("logger", () => { + test("a custom logger keeps receiving llama.cpp log lines after a second getLlama() call", {timeout: 1000 * 60 * 60 * 2}, async () => { + const modelPath = await getModelFile("bge-small-en-v1.5-q8_0.gguf"); + const lines1: string[] = []; + const lines2: string[] = []; + + const llama1 = await getLlama({ + logLevel: LlamaLogLevel.debug, + logger(level, message) { + lines1.push(message); + } + }); + await llama1.loadModel({modelPath}); + + const llama2 = await getLlama({ + logLevel: LlamaLogLevel.debug, + logger(level, message) { + lines2.push(message); + } + }); + await new Promise((resolve) => setTimeout(resolve, 100)); + await llama2.loadModel({modelPath}); + + // llama.cpp emits native log lines through the logger of the most recently created instance. + // Only TS-side logs would reach `lines2` if the native log sink was broken. + expect(lines1.some((line) => line.includes("llama_model_loader"))).toBe(true); + expect(lines2.some((line) => line.includes("llama_model_loader"))).toBe(true); + + await llama2.dispose(); + await llama1.dispose(); + }); + }); +});