Skip to content

Windows: engine logs go to the file only, so redirecting fd 1/2 cannot put log text in database files - #78

Merged
tae898 merged 1 commit into
mainfrom
windows-no-console-logs
Oct 25, 2026
Merged

tae898 merged 1 commit into
mainfrom
windows-no-console-logs

Conversation

@tae898

@tae898 tae898 commented Oct 25, 2026

Copy link
Copy Markdown
Collaborator

Problem

On native Windows, engine log lines were written into database files when the host process redirected fd 1 or 2 after the library started. The runtime caches the OS handle of stdout and stderr at start-up. pytest's default fd capture (any os.dup2 onto fd 1 or 2, a service, an embedding application) closes that handle, a database file opened later gets the same handle value, and the next console log line lands in that file. POSIX is not affected, because writes go to fd 1 and 2 by number. This is the same mechanism as humemai/arcadedb-embedded-python#10, which test-jvm.yml works around with --capture=sys on Windows.

Evidence from the temporary repro workflow (run 40226704699 on branch win-vector-persistence-repro, native Windows, the whole tests/test_vector.py per process):

  • pytest's default fd capture: 1 to 5 failures per 50 runs per test (Invalid vector id -N, Invalid position N (size=65536), 0 results after the reopen), both test_lsm_persistence and test_lsm_vector_search_approximate_persistence.
  • --capture=sys: 0 failures in 400 runs. JVM control with --capture=sys: 0.
  • The failing database snapshots contain engine log text: Doc_0.1.65536.v0.bucket starts with 2026-10-25 19:37:03.759 INFO [LSMVectorIndex] Discovered and loaded graph file ..., and .lsmvecidx files contain Graph build validating ....

Fix

  • Engine logging (both builds, one code path in src/arcadedb/_logdir.py): the generated java.util.logging config has no ConsoleHandler on Windows by default, so the log goes to the per-user log file only. ARCADEDB_LOG_CONSOLE=1 (or true, yes, on) turns the console log on and ARCADEDB_LOG_CONSOLE=0 turns it off, on every platform. A java.util.logging.config.file the user sets still wins. The file-only config is written to logging-file-only.properties (the config with the console stays logging.properties), so two processes with different settings that share a log directory never replace each other's file between the write and the engine's first log call.
  • Windows only, not all platforms. On Linux and macOS the console handler writes to fd 2 by number, so a redirect sends the log where the host sent fd 2 and no file is touched; the console log is also what containers, journald and notebooks rely on. Removing it everywhere would be a behaviour change with no bug behind it. The opt-out exists for anyone who wants file-only logs on any platform.
  • Glue code that wrote to the console directly (native build): NativeExtras.swallowed (callback failures of async writers) and LibraryLoader (jvector library load failures) now log through java.util.logging instead of System.err, so on Windows they go to the log file like the rest. Nothing else in native/src or src/java writes to System.out or System.err; the only remaining use is the jextract downcall trace in NativeSimdOps, which runs only with -Djextract.trace.downcalls=true. The JVM build's glue (src/java/com/arcadedb/python) never printed.
  • native/wheel/parity_wheel.py keeps pytest's default capture on Windows; it is now the regression check. A comment says so. test-jvm.yml keeps --capture=sys for now (comment updated) and can drop it once a default-capture run has passed on its Windows legs.
  • Docs: how-to/logs.adoc has a "Console output" section (where the log goes, ARCADEDB_LOG_CONSOLE, one paragraph on the Windows handle reuse).

Tests

tests/test_log_redirect.py runs on every platform. In a fresh child process it starts the library, then os.dup2s a file onto fd 1 and 2 and closes the original, creates a vector index (PRODUCT quantization, 259 vectors), builds the graph, closes, reopens and queries (the same work as test_lsm_persistence and test_lsm_vector_search_approximate_persistence). It asserts the reopen query is correct and that no file in the database directory contains an engine log line (date, time with milliseconds, level), and that the work did log to the file. On POSIX it passes trivially; on Windows it is the real check. Further tests cover the console opt-in and opt-out (a child that does not redirect, stderr captured by the parent), the platform and env defaults, the rendered config and the config file name that both builds hand to the engine. Existing assertions in test_log_dir.py that named logging.properties now use the name for the setting.

Run locally on Linux against a freshly built native image: test_log_redirect.py, test_log_dir.py, test_native_log_dir.py, test_core.py, test_check_test_skips.py pass. bandit, black, isort, check_no_embedded_name.py and actionlint are clean. The Windows legs of test-native.yml and test-jvm.yml, and a rerun of the repro workflow against this branch's native wheel with pytest's default fd capture, are the verification on the platform that has the bug.

🤖 Generated with Claude Code

…se files

On Windows the runtime caches the OS handle of stdout and stderr at start-up. A host that redirects fd 1 or 2 afterwards (pytest's default fd capture, a service, an embedding application) closes that handle; a database file opened later gets the same handle value and the next console log line is written into it. The native Windows legs of tests/test_vector.py failed 1-5 times in 50 runs per test (Invalid vector id, Invalid position N (size=65536), no result after a reopen), and the failing database snapshots held engine log text.

- _logdir: the generated logging config has no ConsoleHandler on Windows by default. ARCADEDB_LOG_CONSOLE=1/0 turns the console log on or off on every platform; Linux and macOS keep the console log by default. The file-only config has its own file name (logging-file-only.properties) so processes with different settings never replace each other's file. A user's own java.util.logging.config.file still wins.
- native glue: NativeExtras.swallowed and LibraryLoader log through java.util.logging instead of System.err.
- tests/test_log_redirect.py: in a fresh child process, dup2 a file onto fd 1 and 2 after the library started, build a vector index and its graph, reopen, query, and assert that no database file holds a log line. Runs on every platform; on POSIX it passes trivially, on Windows it is the real check.
- parity_wheel.py keeps pytest's default capture on Windows (now the regression check); test-jvm.yml keeps --capture=sys until a default-capture run has passed there.
- docs: how-to/logs.adoc describes the console log and ARCADEDB_LOG_CONSOLE.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant