1#![deny(clippy::expect_used)]
2#![deny(clippy::indexing_slicing)]
3#![deny(clippy::panic)]
4#![deny(clippy::unwrap_used)]
5
6use std::sync::{Mutex, OnceLock};
7
8use llama_cpp_log_decoder::decode_anomaly::DecodeAnomaly;
9use llama_cpp_log_decoder::decode_output::DecodeOutput;
10use llama_cpp_log_decoder::incoming_log_level::IncomingLogLevel;
11use llama_cpp_log_decoder::log_decoder::LogDecoder;
12use llama_cpp_log_decoder::log_level::LogLevel;
13use llama_cpp_log_decoder::log_line::LogLine;
14
15use crate::log_options::LogOptions;
16
17struct LogSource {
18 decoder: Mutex<LogDecoder>,
19 target: &'static str,
20 options: LogOptions,
21}
22
23impl LogSource {
24 const fn new(target: &'static str, options: LogOptions) -> Self {
25 Self {
26 decoder: Mutex::new(LogDecoder::new()),
27 target,
28 options,
29 }
30 }
31}
32
33static LLAMA_SOURCE: OnceLock<LogSource> = OnceLock::new();
34static GGML_SOURCE: OnceLock<LogSource> = OnceLock::new();
35
36#[cfg(target_env = "msvc")]
37const fn ggml_level_to_u32(level: llama_cpp_bindings_sys::ggml_log_level) -> u32 {
38 level.cast_unsigned()
39}
40
41#[cfg(not(target_env = "msvc"))]
42const fn ggml_level_to_u32(level: llama_cpp_bindings_sys::ggml_log_level) -> u32 {
43 level
44}
45
46const fn ggml_level_to_incoming(raw: llama_cpp_bindings_sys::ggml_log_level) -> IncomingLogLevel {
47 match raw {
48 llama_cpp_bindings_sys::GGML_LOG_LEVEL_NONE => IncomingLogLevel::None,
49 llama_cpp_bindings_sys::GGML_LOG_LEVEL_DEBUG => IncomingLogLevel::Debug,
50 llama_cpp_bindings_sys::GGML_LOG_LEVEL_INFO => IncomingLogLevel::Info,
51 llama_cpp_bindings_sys::GGML_LOG_LEVEL_WARN => IncomingLogLevel::Warn,
52 llama_cpp_bindings_sys::GGML_LOG_LEVEL_ERROR => IncomingLogLevel::Error,
53 llama_cpp_bindings_sys::GGML_LOG_LEVEL_CONT => IncomingLogLevel::Cont,
54 other => IncomingLogLevel::Unknown(ggml_level_to_u32(other)),
55 }
56}
57
58fn resolve_record(line: LogLine, demote_info_to_debug: bool) -> (log::Level, String) {
59 let effective_level =
60 if demote_info_to_debug && matches!(line.level, LogLevel::Info | LogLevel::None) {
61 LogLevel::Debug
62 } else {
63 line.level
64 };
65
66 match effective_level {
67 LogLevel::Debug => (log::Level::Debug, line.text),
68 LogLevel::Info | LogLevel::None => (log::Level::Info, line.text),
69 LogLevel::Warn => (log::Level::Warn, line.text),
70 LogLevel::Error => (log::Level::Error, line.text),
71 LogLevel::Unknown(raw) => (
72 log::Level::Warn,
73 format!("[unknown level {raw}] {}", line.text),
74 ),
75 }
76}
77
78fn dispatch_line(source: &LogSource, line: LogLine) {
79 let (level, message) = resolve_record(line, source.options.demote_info_to_debug);
80 log::log!(target: source.target, level, "{message}");
81}
82
83fn dispatch_output(source: &LogSource, output: DecodeOutput) {
84 match output {
85 DecodeOutput::None => {}
86 DecodeOutput::Line(line) => dispatch_line(source, line),
87 DecodeOutput::TwoLines { earlier, current } => {
88 dispatch_line(source, earlier);
89 dispatch_line(source, current);
90 }
91 }
92}
93
94fn dispatch_anomaly(source: &LogSource, anomaly: DecodeAnomaly) {
95 log::warn!(
96 target: source.target,
97 "llama.cpp log decoder anomaly: {anomaly:?}",
98 );
99}
100
101unsafe extern "C" fn logs_to_log(
102 raw_level: llama_cpp_bindings_sys::ggml_log_level,
103 text_ptr: *const std::os::raw::c_char,
104 data_ptr: *mut std::os::raw::c_void,
105) {
106 let source: &LogSource = unsafe { &*data_ptr.cast::<LogSource>() };
107
108 if source.options.disabled {
109 return;
110 }
111
112 if text_ptr.is_null() {
113 log::warn!(
114 target: source.target,
115 "received NULL text pointer from llama.cpp log callback",
116 );
117 return;
118 }
119
120 let text_cstr = unsafe { std::ffi::CStr::from_ptr(text_ptr) };
121 let text = text_cstr.to_string_lossy();
122
123 let incoming = ggml_level_to_incoming(raw_level);
124
125 let result = {
126 let mut decoder = source
127 .decoder
128 .lock()
129 .unwrap_or_else(std::sync::PoisonError::into_inner);
130 decoder.feed(incoming, &text)
131 };
132
133 dispatch_output(source, result.output);
134
135 if let Some(anomaly) = result.anomaly {
136 dispatch_anomaly(source, anomaly);
137 }
138}
139
140pub fn send_logs_to_log(options: LogOptions) {
141 let llama_source: *const LogSource =
142 LLAMA_SOURCE.get_or_init(|| LogSource::new("llama.cpp", options.clone()));
143 let ggml_source: *const LogSource = GGML_SOURCE.get_or_init(|| LogSource::new("ggml", options));
144
145 unsafe {
146 llama_cpp_bindings_sys::llama_log_set(
147 Some(logs_to_log),
148 llama_source.cast::<std::os::raw::c_void>().cast_mut(),
149 );
150 llama_cpp_bindings_sys::ggml_log_set(
151 Some(logs_to_log),
152 ggml_source.cast::<std::os::raw::c_void>().cast_mut(),
153 );
154 }
155}
156
157#[cfg(test)]
158mod tests {
159 use std::sync::{Mutex, Once};
160
161 use llama_cpp_log_decoder::incoming_log_level::IncomingLogLevel;
162 use log::{Level, Log, Metadata, Record};
163 use serial_test::serial;
164
165 use super::{
166 GGML_SOURCE, LLAMA_SOURCE, LogSource, ggml_level_to_incoming, logs_to_log, send_logs_to_log,
167 };
168 use crate::log_options::LogOptions;
169
170 #[derive(Clone, Debug)]
171 struct CapturedRecord {
172 level: Level,
173 target: String,
174 message: String,
175 }
176
177 struct TestLogger {
178 records: Mutex<Vec<CapturedRecord>>,
179 }
180
181 impl Log for TestLogger {
182 fn enabled(&self, _: &Metadata) -> bool {
183 true
184 }
185
186 fn log(&self, record: &Record) {
187 let mut guard = self
188 .records
189 .lock()
190 .unwrap_or_else(std::sync::PoisonError::into_inner);
191 guard.push(CapturedRecord {
192 level: record.level(),
193 target: record.target().to_owned(),
194 message: record.args().to_string(),
195 });
196 }
197
198 fn flush(&self) {}
199 }
200
201 static TEST_LOGGER: TestLogger = TestLogger {
202 records: Mutex::new(Vec::new()),
203 };
204 static INSTALL: Once = Once::new();
205
206 fn ensure_test_logger_installed() {
207 INSTALL.call_once(|| {
208 if log::set_logger(&TEST_LOGGER).is_ok() {
209 log::set_max_level(log::LevelFilter::Trace);
210 }
211 });
212 }
213
214 fn records_for(target: &str) -> Vec<CapturedRecord> {
215 let guard = TEST_LOGGER
216 .records
217 .lock()
218 .unwrap_or_else(std::sync::PoisonError::into_inner);
219 guard
220 .iter()
221 .filter(|record| record.target == target)
222 .cloned()
223 .collect()
224 }
225
226 fn invoke_callback(
227 level: llama_cpp_bindings_sys::ggml_log_level,
228 text: &std::ffi::CStr,
229 source: &LogSource,
230 ) {
231 let ptr = std::ptr::from_ref(source)
232 .cast::<std::os::raw::c_void>()
233 .cast_mut();
234 unsafe {
235 logs_to_log(level, text.as_ptr(), ptr);
236 }
237 }
238
239 #[test]
240 fn ggml_level_to_incoming_known_constants() {
241 assert_eq!(
242 ggml_level_to_incoming(llama_cpp_bindings_sys::GGML_LOG_LEVEL_NONE),
243 IncomingLogLevel::None,
244 );
245 assert_eq!(
246 ggml_level_to_incoming(llama_cpp_bindings_sys::GGML_LOG_LEVEL_DEBUG),
247 IncomingLogLevel::Debug,
248 );
249 assert_eq!(
250 ggml_level_to_incoming(llama_cpp_bindings_sys::GGML_LOG_LEVEL_INFO),
251 IncomingLogLevel::Info,
252 );
253 assert_eq!(
254 ggml_level_to_incoming(llama_cpp_bindings_sys::GGML_LOG_LEVEL_WARN),
255 IncomingLogLevel::Warn,
256 );
257 assert_eq!(
258 ggml_level_to_incoming(llama_cpp_bindings_sys::GGML_LOG_LEVEL_ERROR),
259 IncomingLogLevel::Error,
260 );
261 assert_eq!(
262 ggml_level_to_incoming(llama_cpp_bindings_sys::GGML_LOG_LEVEL_CONT),
263 IncomingLogLevel::Cont,
264 );
265 }
266
267 #[test]
268 fn ggml_level_to_incoming_unknown_value() {
269 assert_eq!(
270 ggml_level_to_incoming(9999),
271 IncomingLogLevel::Unknown(9999)
272 );
273 }
274
275 #[test]
276 fn dispatch_when_disabled() {
277 ensure_test_logger_installed();
278
279 let target = "test-dispatch-when-disabled";
280 let source = LogSource::new(target, LogOptions::default().with_logs_enabled(false));
281 invoke_callback(
282 llama_cpp_bindings_sys::GGML_LOG_LEVEL_INFO,
283 c"hello\n",
284 &source,
285 );
286
287 assert!(records_for(target).is_empty());
288 }
289
290 #[test]
291 fn demote_info_to_debug_on_info() {
292 ensure_test_logger_installed();
293
294 let target = "test-demote-info-on-info";
295 let source = LogSource::new(
296 target,
297 LogOptions::default().with_demote_info_to_debug(true),
298 );
299 invoke_callback(
300 llama_cpp_bindings_sys::GGML_LOG_LEVEL_INFO,
301 c"info-line\n",
302 &source,
303 );
304
305 assert!(records_for(target).iter().any(|record| {
306 record.level == Level::Debug && record.message.contains("info-line")
307 }));
308 }
309
310 #[test]
311 fn demote_info_to_debug_on_warn() {
312 ensure_test_logger_installed();
313
314 let target = "test-demote-info-on-warn";
315 let source = LogSource::new(
316 target,
317 LogOptions::default().with_demote_info_to_debug(true),
318 );
319 invoke_callback(
320 llama_cpp_bindings_sys::GGML_LOG_LEVEL_WARN,
321 c"warn-line\n",
322 &source,
323 );
324
325 assert!(
326 records_for(target).iter().any(|record| {
327 record.level == Level::Warn && record.message.contains("warn-line")
328 })
329 );
330 }
331
332 #[test]
333 fn dispatch_unknown_level() {
334 ensure_test_logger_installed();
335
336 let target = "test-dispatch-unknown-level";
337 let source = LogSource::new(target, LogOptions::default());
338 invoke_callback(9999, c"weird\n", &source);
339
340 assert!(records_for(target).iter().any(|record| {
341 record.level == Level::Warn
342 && record.message.contains("[unknown level 9999]")
343 && record.message.contains("weird")
344 }));
345 }
346
347 #[test]
348 fn dispatch_orphan_cont_anomaly() {
349 ensure_test_logger_installed();
350
351 let target = "test-dispatch-orphan-cont";
352 let source = LogSource::new(target, LogOptions::default());
353 invoke_callback(
354 llama_cpp_bindings_sys::GGML_LOG_LEVEL_CONT,
355 c"ghost\n",
356 &source,
357 );
358
359 assert!(records_for(target).iter().any(|record| {
360 record.level == Level::Warn && record.message.contains("OrphanCont")
361 }));
362 }
363
364 #[test]
365 #[serial]
366 fn send_logs_to_log_initialization() {
367 ensure_test_logger_installed();
368 send_logs_to_log(LogOptions::default());
369
370 assert!(LLAMA_SOURCE.get().is_some());
371 assert!(GGML_SOURCE.get().is_some());
372 }
373
374 #[test]
375 fn null_text_pointer() {
376 ensure_test_logger_installed();
377
378 let target = "test-null-text-pointer";
379 let source = LogSource::new(target, LogOptions::default());
380 let source_ptr = std::ptr::from_ref(&source)
381 .cast::<std::os::raw::c_void>()
382 .cast_mut();
383 unsafe {
384 logs_to_log(
385 llama_cpp_bindings_sys::GGML_LOG_LEVEL_INFO,
386 std::ptr::null(),
387 source_ptr,
388 );
389 }
390
391 assert!(records_for(target).iter().any(|record| {
392 record.level == Level::Warn && record.message.contains("NULL text pointer")
393 }));
394 }
395
396 #[test]
397 #[expect(
398 clippy::panic,
399 reason = "deliberate panic to poison the decoder mutex for fault-injection coverage"
400 )]
401 fn decoder_mutex_poison() {
402 ensure_test_logger_installed();
403
404 let target = "test-decoder-mutex-poison";
405 let source = LogSource::new(target, LogOptions::default());
406
407 std::thread::scope(|scope| {
408 let handle = scope.spawn(|| {
409 let _guard = source
410 .decoder
411 .lock()
412 .unwrap_or_else(std::sync::PoisonError::into_inner);
413 panic!("intentional poison");
414 });
415 let _ = handle.join();
416 });
417
418 assert!(source.decoder.is_poisoned());
419
420 invoke_callback(
421 llama_cpp_bindings_sys::GGML_LOG_LEVEL_INFO,
422 c"after-poison\n",
423 &source,
424 );
425
426 assert!(
427 records_for(target)
428 .iter()
429 .any(|record| record.message.contains("after-poison"))
430 );
431 }
432}