libflashrom: Update the API for Logger Callback

The initial implementation does not account for user_data, requiring
the calling application to use a global scope. This may lead to issues
related to object lifecycle management and other architectural
concerns.

This patch adds user_data to the user’s log callback. Moreover, it
performs message formatting, so the application only needs to pass
the formatted string to the selected output.

The change does not break the existing logging API but extends it.
A new API version is introduced with the v2 suffix.

Testing: Both unit tests and CLI tools serve as libflashrom clients.
    All unit tests run successfully.

Change-Id: Iea738bd371fa3d69b9cf222c89ee67490d30af39
Signed-off-by: Dmitry Zhadinets <dzhadinets@gmail.com>
Reviewed-on: https://review.coreboot.org/c/flashrom/+/86875
Reviewed-by: Anastasia Klimchuk <aklm@chromium.org>
Reviewed-by: Peter Marheine <pmarheine@chromium.org>
Tested-by: build bot (Jenkins) <no-reply@coreboot.org>

include/flash.h

@@ -730,7 +730,14 @@ struct cli_progress {
 void print_chip_support_status(const struct flashchip *chip);
 
 /* libflashrom.c */
-/* Let gcc and clang check for correct printf-style format strings. */
+/*
+ * Let gcc and clang check for correct printf-style format strings.
+ * Avoid using formatted messages longer than 256 characters.
+ * The new public logging API formats messages and passes a ready-to-print
+ * string  to the user callback for performance reasons.
+ * Therefore, any message exceeding 256 characters will be truncated,
+ * and an ERANGE error code will be returned.
+ */
 int print(enum flashrom_log_level level, const char *fmt, ...)
 #ifdef __MINGW32__
 #  ifndef __MINGW_PRINTF_FORMAT

include/libflashrom.h

@@ -69,6 +69,24 @@ typedef int(flashrom_log_callback)(enum flashrom_log_level, const char *format,
  */
 void flashrom_set_log_callback(flashrom_log_callback *log_callback);
 
+typedef void (flashrom_log_callback_v2)(
+	enum flashrom_log_level,
+	const char* message,
+	void* user_data);
+/**
+ * @brief Set the log callback function.
+ *
+ * Set a callback function which will be invoked whenever libflashrom wants
+ * to output messages. This allows frontends to do whatever they see fit with
+ * such messages, e.g. write them to syslog, or to a file, or print them in a
+ * GUI window, etc.
+ * The message is formatted using vsnprintf
+ *
+ * @param log_callback Pointer to the new log callback function.
+ * @param user_data A pointer to data managed by the caller.
+ */
+void flashrom_set_log_callback_v2(flashrom_log_callback_v2 *log_callback, void* user_data);
+
 enum flashrom_progress_stage {
 	FLASHROM_PROGRESS_READ,
 	FLASHROM_PROGRESS_WRITE,

libflashrom.c

@@ -31,6 +31,8 @@
 
 /** Pointer to log callback function. */
 static flashrom_log_callback *global_log_callback = NULL;
+static flashrom_log_callback_v2 *global_log_callback_v2 = NULL;
+static void *global_log_user_data = NULL;
 
 int flashrom_init(const int perform_selfcheck)
 {
@@ -50,6 +52,49 @@ void flashrom_set_log_callback(flashrom_log_callback *const log_callback)
 {
 	global_log_callback = log_callback;
 }
+
+/** @private */
+static int format_message_and_invoke_log_callback_v2(enum flashrom_log_level level,
+						const char *format, va_list args)
+{
+	char message[LOG_MESSAGE_LENGTH_LIMIT] = {0};
+	int actual_len;
+
+	/* sanity check */
+	if (!global_log_callback_v2)
+		return -EINVAL;
+
+	actual_len = vsnprintf(message, sizeof(message), format, args);
+
+	if (actual_len < 0)
+		return actual_len;
+
+	global_log_callback_v2(level, message, global_log_user_data);
+
+	if ((size_t)actual_len >= sizeof(message)) {
+		snprintf(message, sizeof(message),
+			"%zu characters were truncated from the previous log message",
+			(size_t)actual_len - sizeof(message) + 1);
+		global_log_callback_v2(FLASHROM_MSG_WARN, message, global_log_user_data);
+		return -ERANGE;
+	}
+	return 0;
+}
+
+void flashrom_set_log_callback_v2(flashrom_log_callback_v2 *const log_callback, void* user_data)
+{
+	if (!log_callback) {
+		/* Reset v1 callback only if it was installed by flashrom_set_log_callback_v2 op */
+		if (global_log_callback == format_message_and_invoke_log_callback_v2) {
+			global_log_callback = NULL;
+		}
+	}
+	else
+		global_log_callback = format_message_and_invoke_log_callback_v2;
+	global_log_callback_v2 = log_callback;
+	global_log_user_data = user_data;
+}
+
 /** @private */
 int print(const enum flashrom_log_level level, const char *const fmt, ...)
 {

libflashrom.map

@@ -24,6 +24,7 @@ LIBFLASHROM_1.0 {
     flashrom_programmer_init;
     flashrom_programmer_shutdown;
     flashrom_set_log_callback;
+    flashrom_set_log_callback_v2;
     flashrom_set_progress_callback;
     flashrom_set_progress_callback_v2;
     flashrom_shutdown;

meson.build

@@ -652,6 +652,8 @@ endif
 
 cargs += '-DCONFIG_DEFAULT_PROGRAMMER_ARGS="' + config_default_programmer_args + '"'
 
+cargs += '-DLOG_MESSAGE_LENGTH_LIMIT=' + get_option('log_message_length_limit').to_string()
+
 if get_option('llvm_cov').enabled()
   cargs += ['-fprofile-instr-generate', '-fcoverage-mapping']
   link_args += ['-fprofile-instr-generate', '-fcoverage-mapping']

meson_options.txt

@@ -27,3 +27,5 @@ option('delay_minimum_sleep_us', type : 'integer', min : 0, value : 100,
        description : 'Minimum time in microseconds to suspend execution for (rather than polling) when a delay is required.'
                    + ' Larger values may perform better on machines with low timer resolution, at the cost of increased power.')
 option('rpmc', type : 'feature', value : 'auto', description : 'Support for Replay Protected Monotonic Counter (RPMC) commands as specified by JESD260')
+option('log_message_length_limit', type : 'integer', min : 64, max : 1024, value : 256,
+       description : 'Log message length limit for v2 logging API')

tests/libflashrom.c

@@ -0,0 +1,66 @@
+/*
+ * This file is part of the flashrom project.
+ *
+ * Copyright 2025 Dmitry Zhadinets (dzhadinets@gmail.com)
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; version 2 of the License.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ */
+
+#include <stdlib.h>
+
+#include <include/test.h>
+#include "tests.h"
+#include "libflashrom.h"
+#include "flash.h"
+
+static int test_log_callback(enum flashrom_log_level level, const char *format,
+			     va_list vargs)
+{
+	/* check that loglevel has passed corectly */
+	assert_int_equal(level, FLASHROM_MSG_INFO);
+	char message[3] = {0};
+	vsnprintf(message, 3, format, vargs);
+	assert_string_equal(message, "1\n");
+	return 0x666 + 1;
+}
+
+static void test_log_callback_v2(enum flashrom_log_level level,
+				 const char *message, void *user_data)
+{
+	/* check that loglevel has passed corectly */
+	assert_int_equal(level, FLASHROM_MSG_ERROR);
+	/* check that user dta has passed */
+	assert_ptr_not_equal(user_data, 0);
+	/* check that user_data is correct */
+	assert_int_equal(*(int *)(user_data), 100500);
+	/* check that format is working correctly */
+	assert_string_equal(message, "2\n");
+	*(int*)user_data = 0x666 + 2;
+}
+
+void flashrom_set_log_callback_test_success(void **state)
+{
+	(void)state; /* unused */
+	flashrom_set_log_callback(test_log_callback);
+	/* check that callback is called */
+	assert_int_equal(print(FLASHROM_MSG_INFO, "1%s", "\n"), 0x666 + 1);
+	flashrom_set_log_callback(NULL);
+}
+
+void flashrom_set_log_callback_v2_test_success(void **state)
+{
+	(void)state; /* unused */
+	int user_data = 100500;
+	flashrom_set_log_callback_v2(test_log_callback_v2, &user_data);
+	print(FLASHROM_MSG_ERROR, "2%s", "\n");
+	/* check that callback is called */
+	assert_int_equal(user_data, 0x666 + 2);
+	flashrom_set_log_callback_v2(NULL, NULL);
+}

tests/meson.build

@@ -17,6 +17,7 @@ test_srcs = files(
   'libusb_wraps.c',
   'helpers.c',
   'flashrom.c',
+  'libflashrom.c',
   'spi25.c',
   'lifecycle.c',
   'layout.c',

tests/tests.c

@@ -478,6 +478,12 @@ int main(int argc, char *argv[])
 	};
 	ret |= cmocka_run_group_tests_name("flashrom.c tests", flashrom_tests, NULL, NULL);
 
+	const struct CMUnitTest libflashrom_tests[] = {
+		cmocka_unit_test(flashrom_set_log_callback_test_success),
+		cmocka_unit_test(flashrom_set_log_callback_v2_test_success),
+	};
+	ret |= cmocka_run_group_tests_name("libflashrom.c tests", libflashrom_tests, NULL, NULL);
+
 	const struct CMUnitTest spi25_tests[] = {
 		cmocka_unit_test(spi_write_enable_test_success),
 		cmocka_unit_test(spi_write_disable_test_success),

tests/tests.h

@@ -31,6 +31,10 @@ void reverse_bytes_test_success(void **state);
 /* flashrom.c */
 void flashbuses_to_text_test_success(void **state);
 
+/* libflashrom.c */
+void flashrom_set_log_callback_test_success(void **state);
+void flashrom_set_log_callback_v2_test_success(void **state);
+
 /* spi25.c */
 void spi_write_enable_test_success(void **state);
 void spi_write_disable_test_success(void **state);