Add logstorage for python logging

Author: evertlammerts

.github/workflows/code_quality.yml

@@ -32,7 +32,10 @@ jobs:
         uses: astral-sh/setup-uv@v7
         with:
           version: "0.9.0"
-          python-version: "3.12"
+          # 3.13: the cmake-format pre-commit hook is pinned to python3.13
+          # (cmakelang crashes under 3.14). Keeping this in sync means the hook
+          # resolves to the running interpreter instead of hunting PATH.
+          python-version: "3.13"
 
       - name: pre-commit (cache)
         uses: actions/cache@v4

.pre-commit-config.yaml

@@ -29,6 +29,12 @@ repos:
     rev: v0.6.13
     hooks:
       - id: cmake-format
+        # cmakelang is unmaintained and crashes under Python 3.14
+        # ("Cannot use capturing groups in re.Scanner"). Pin this hook's
+        # environment to 3.13 so it never picks up a 3.14 interpreter. The
+        # code_quality CI job provisions Python 3.13 to match, so the hook
+        # resolves to the running interpreter there.
+        language_version: python3.13
 
   - repo: https://github.com/pre-commit/mirrors-mypy
     rev: v1.18.2

src/duckdb_py/CMakeLists.txt

@@ -19,6 +19,7 @@ add_library(
   importer.cpp
   map.cpp
   path_like.cpp
+  python_log_storage.cpp
   pyconnection.cpp
   pyexpression.cpp
   pyfilesystem.cpp

src/duckdb_py/include/duckdb_python/python_log_storage.hpp

@@ -0,0 +1,37 @@
+//===----------------------------------------------------------------------===//
+//                         DuckDB
+//
+// duckdb_python/python_log_storage.hpp
+//
+//
+//===----------------------------------------------------------------------===//
+
+#pragma once
+
+#include "duckdb/logging/log_storage.hpp"
+#include "duckdb/logging/logging.hpp"
+
+namespace duckdb {
+
+class PythonLogStorage : public LogStorage {
+public:
+	PythonLogStorage() = default;
+	~PythonLogStorage() override = default;
+
+	const string GetStorageName() override {
+		return "python_log_storage";
+	}
+
+	void WriteLogEntry(timestamp_t timestamp, LogLevel level, const string &log_type, const string &log_message,
+	                   const RegisteredLoggingContext &context) override;
+	void WriteLogEntries(DataChunk &chunk, const RegisteredLoggingContext &context) override;
+	void FlushAll() override {
+	}
+	void Flush(LoggingTargetTable table) override {
+	}
+	bool IsEnabled(LoggingTargetTable table) override {
+		return true;
+	}
+};
+
+} // namespace duckdb

src/duckdb_py/pyconnection.cpp

@@ -35,6 +35,8 @@
 #include "duckdb_python/numpy/numpy_type.hpp"
 #include "duckdb/main/prepared_statement.hpp"
 #include "duckdb_python/jupyter_progress_bar_display.hpp"
+#include "duckdb_python/python_log_storage.hpp"
+#include "duckdb/logging/log_manager.hpp"
 #include "duckdb_python/pyfilesystem.hpp"
 #include "duckdb/main/client_config.hpp"
 #include "duckdb/function/table/read_csv.hpp"
@@ -2283,6 +2285,22 @@ shared_ptr<DuckDBPyConnection> DuckDBPyConnection::Connect(const py::object &dat
 	auto res = FetchOrCreateInstance(database, config);
 	auto &client_context = *res->con.GetConnection().context;
 	SetDefaultConfigArguments(client_context);
+	{
+		auto &db_instance = *res->con.GetDatabase().instance;
+		auto &log_manager = db_instance.GetLogManager();
+		auto storage = make_shared_ptr<PythonLogStorage>();
+		shared_ptr<LogStorage> storage_base = storage;
+		// RegisterLogStorage returns false if the name is already registered on this
+		// DatabaseInstance. Instances are cached and shared across connections/cursors, so
+		// only configure logging on the first registration. SetLogStorage/SetEnableLogging/
+		// SetLogLevel are NOT idempotent — re-running them on every Connect() would silently
+		// stomp a user's explicit `SET enable_logging` / `SET logging_level` / storage choice.
+		if (log_manager.RegisterLogStorage("python_log_storage", storage_base)) {
+			log_manager.SetLogStorage(db_instance, "python_log_storage");
+			log_manager.SetEnableLogging(true);
+			log_manager.SetLogLevel(LogLevel::LOG_WARNING);
+		}
+	}
 	return res;
 }
 

src/duckdb_py/python_log_storage.cpp

@@ -0,0 +1,92 @@
+#include "duckdb_python/python_log_storage.hpp"
+#include "duckdb_python/pybind11/pybind_wrapper.hpp"
+#include "duckdb/common/types/data_chunk.hpp"
+#include "duckdb/common/types/vector.hpp"
+#include "duckdb/logging/logging.hpp"
+
+namespace duckdb {
+
+static int LogLevelToPython(LogLevel level) {
+	switch (level) {
+	case LogLevel::LOG_TRACE:
+	case LogLevel::LOG_DEBUG:
+		return 10; // logging.DEBUG
+	case LogLevel::LOG_INFO:
+		return 20; // logging.INFO
+	case LogLevel::LOG_WARNING:
+		return 30; // logging.WARNING
+	case LogLevel::LOG_ERROR:
+		return 40; // logging.ERROR
+	case LogLevel::LOG_FATAL:
+		return 50; // logging.CRITICAL
+	default:
+		return 30;
+	}
+}
+
+static int LevelStringToPython(const string &level_str) {
+	if (level_str == "TRACE" || level_str == "DEBUG") {
+		return 10;
+	}
+	if (level_str == "INFO") {
+		return 20;
+	}
+	if (level_str == "WARNING") {
+		return 30;
+	}
+	if (level_str == "ERROR") {
+		return 40;
+	}
+	if (level_str == "FATAL") {
+		return 50;
+	}
+	return 30;
+}
+
+// Both write methods run on engine worker threads and invoke arbitrary user Python (the
+// handlers installed on the "duckdb" logger). The engine calls these directly from query
+// binding/execution with NO surrounding try/catch (see LogManager::WriteLogEntry), so an
+// exception escaping here would fail the user's query. Logging is a side effect — it must
+// never do that. Hence every body swallows all exceptions.
+//
+// Note also that the engine holds LogManager::lock (a non-recursive mutex) across this call.
+// A handler that re-enters DuckDB on the same thread and emits another log entry would
+// self-deadlock on that lock — outside our control, but worth knowing.
+
+void PythonLogStorage::WriteLogEntry(timestamp_t, LogLevel level, const string &, const string &log_message,
+                                     const RegisteredLoggingContext &) {
+	if (!Py_IsInitialized()) {
+		return; // interpreter is finalizing — acquiring the GIL would crash
+	}
+	try {
+		py::gil_scoped_acquire gil;
+		auto logging = py::module::import("logging");
+		auto logger = logging.attr("getLogger")("duckdb");
+		logger.attr("log")(LogLevelToPython(level), log_message);
+	} catch (...) {
+		// Logging must not disrupt query execution.
+	}
+}
+
+void PythonLogStorage::WriteLogEntries(DataChunk &chunk, const RegisteredLoggingContext &) {
+	if (!Py_IsInitialized()) {
+		return; // interpreter is finalizing — acquiring the GIL would crash
+	}
+	try {
+		py::gil_scoped_acquire gil;
+		auto logging = py::module::import("logging");
+		auto logger = logging.attr("getLogger")("duckdb");
+		// DataChunk is in LOG_ENTRIES format: context_id, timestamp, type, log_level, message.
+		// log_level (idx 3) and message (idx 4) are both VARCHAR; the chunk is freshly
+		// allocated by the engine so the vectors are flat.
+		auto level_data = FlatVector::GetData<string_t>(chunk.data[3]);
+		auto message_data = FlatVector::GetData<string_t>(chunk.data[4]);
+		for (idx_t i = 0; i < chunk.size(); i++) {
+			logger.attr("log")(LevelStringToPython(level_data[i].GetString()), message_data[i].GetString());
+		}
+	} catch (...) {
+		// Logging must not disrupt query execution.
+	}
+}
+
+} // namespace duckdb

tests/fast/test_python_log_storage.py

@@ -0,0 +1,28 @@
+import logging
+
+import duckdb
+
+
+def test_warning_routed_to_python_logging(caplog):
+    with caplog.at_level(logging.WARNING, logger="duckdb"):
+        con = duckdb.connect()
+        # Pin lambda_syntax to DEFAULT so the deprecated arrow (->) form reliably emits a
+        # DUCKDB_LOG_WARNING. DEFAULT is the current engine default, but it is explicitly
+        # slated to change ("before DuckDB's next release"); pinning keeps this test
+        # exercising the warning path across future submodule bumps.
+        con.execute("SET lambda_syntax='DEFAULT'")
+        con.execute("SELECT list_transform([1, 2, 3], x -> x + 1)")
+    deprecation_records = [r for r in caplog.records if "deprecated" in r.message.lower()]
+    assert deprecation_records, "expected a deprecation warning routed to the 'duckdb' logger"
+    assert all(r.name == "duckdb" for r in deprecation_records)
+    assert all(r.levelno == logging.WARNING for r in deprecation_records)
+
+
+def test_warning_not_emitted_for_clean_queries(caplog):
+    with caplog.at_level(logging.WARNING, logger="duckdb"):
+        con = duckdb.connect()
+        con.execute("SELECT 1 + 1").fetchone()
+    # Assert the absence of the deprecation warning specifically rather than requiring zero
+    # records total — an incidental connect-time warning (e.g. the macOS Rosetta notice on
+    # some hardware) would otherwise make this flaky.
+    assert not [r for r in caplog.records if "deprecated" in r.message.lower()]