Native: write the engine log to the per-user log directory, never the working directory

docs/modules/ROOT/nav.adoc

@@ -5,6 +5,7 @@
 * How-to
 ** xref:how-to/databases-and-queries.adoc[Databases and queries]
 ** xref:how-to/concurrency.adoc[Concurrency, processes and crashes]
+** xref:how-to/logs.adoc[Where the logs go]
 * Development
 ** xref:development/ci.adoc[Continuous integration]
 ** xref:development/release.adoc[Release]

docs/modules/ROOT/pages/how-to/logs.adoc

@@ -0,0 +1,43 @@
+= Where the logs go
+:description: Where the engine writes its log file on the arcadedb and arcadedb-jvm packages, how to move it, and what the packages never write.
+
+Neither package writes a `log` directory into your working directory. The engine's own default is `./log/arcadedb.log`, relative to wherever the process started. Both packages replace it with a per-user directory, so a read-only working directory or a notebook that starts anywhere leaves no files behind.
+
+== Default location
+
+The log directory is `arcadedb/log` under your state directory:
+
+[cols="1,3"]
+|===
+| Platform | Directory
+
+| Linux
+| `$XDG_STATE_HOME/arcadedb/log`, or `~/.local/state/arcadedb/log` when `XDG_STATE_HOME` is not set to an absolute path
+
+| macOS
+| `~/Library/Logs/arcadedb/log`
+
+| Windows
+| `%LOCALAPPDATA%\arcadedb\log`
+|===
+
+When the directory cannot be created or written, the package logs a warning and uses a new `arcadedb-log-*` directory under the system temp directory.
+
+The directory holds the engine log (`arcadedb.log.0`, `arcadedb.log.1` and so on, up to 10 files of 100 MB), and the `logging.properties` that the package writes for the engine. The `arcadedb-jvm` package also keeps the JVM crash file `hs_err_pid<pid>.log` there.
+
+== Choose the directory
+
+Set `ARCADEDB_LOG_DIR` before the first database is opened. The first call that starts the engine reads it, so setting it later has no effect in the same process.
+
+[source,bash]
+----
+export ARCADEDB_LOG_DIR=/var/log/my-app/arcadedb
+----
+
+== Settings that win over `ARCADEDB_LOG_DIR`
+
+The packages pass two Java system properties to the engine: `arcadedb.server.logsDirectory` (the directory) and `java.util.logging.config.file` (the `logging.properties` in it). If you set one of them yourself, yours is kept and the other default still applies.
+
+`arcadedb-jvm`:: Add the property to `jvm_kwargs={"jvm_args": [...]}` or to the environment variable `ARCADEDB_JVM_ARGS`, for example `-Darcadedb.server.logsDirectory=/var/log/arcadedb`.
+
+`arcadedb` (native):: Add the property to the environment variable `ARCADEDB_NATIVE_ISOLATE_ARGS`. It takes space-separated isolate arguments, so a directory in it cannot contain a space. For example `ARCADEDB_NATIVE_ISOLATE_ARGS=-Darcadedb.server.logsDirectory=/var/log/arcadedb`. Use `ARCADEDB_LOG_DIR` for a directory with a space in its name.

src/arcadedb/_logdir.py

@@ -0,0 +1,133 @@
+"""Where the engine writes its log, for both builds (the JVM build and the native build).
+
+The engine's own ``arcadedb-log.properties`` writes ``./log/arcadedb.log`` into the working directory. Both builds move the file
+log to a per-user directory instead: ``ARCADEDB_LOG_DIR`` if set, else ``arcadedb/log`` under the user's state directory. They
+write a ``logging.properties`` there whose file pattern is ``${arcadedb.server.logsDirectory}/arcadedb.log`` and point two
+system properties at it: ``arcadedb.server.logsDirectory`` (the directory) and ``java.util.logging.config.file`` (that file).
+The JVM build sets them as JVM arguments (``jvm.py``), the native build as isolate arguments (``_native/lib.py``). The engine
+reads both when it first logs, so they have to be in place before the first engine call. This module has no JVM and no JPype.
+"""
+
+import os
+import re
+import sys
+import tempfile
+from pathlib import Path
+
+from ._logging import get_logger
+
+_LOGGER = get_logger(__name__)
+
+LOG_DIR_ENV = "ARCADEDB_LOG_DIR"
+LOGGING_CONFIG_NAME = "logging.properties"
+
+# The engine's arcadedb-log.properties without its file pattern, for the native build: the image holds the engine's copy as a
+# resource, but an isolate argument has to name a real file, and there is no jar to read it from. tests/test_log_dir.py compares
+# this text with the file in the engine jar, so an engine upgrade that changes the file fails there until this is updated.
+NATIVE_ENGINE_LOG_PROPERTIES = """\
+handlers = java.util.logging.ConsoleHandler, java.util.logging.FileHandler
+.level = INFO
+io.undertow.level=WARNING
+org.xnio.level=WARNING
+org.jboss.level=WARNING
+org.apache.ratis.grpc.server.GrpcLogAppender.level = SEVERE
+com.arcadedb.level = INFO
+java.util.logging.ConsoleHandler.level = INFO
+java.util.logging.ConsoleHandler.formatter = com.arcadedb.utility.AnsiLogFormatter
+java.util.logging.FileHandler.level = INFO
+java.util.logging.FileHandler.formatter = com.arcadedb.log.LogFormatter
+java.util.logging.FileHandler.limit=100000000
+java.util.logging.FileHandler.count=10
+"""
+
+
+def state_base_dir() -> Path:
+    """Per-user base directory for state and logs, by platform (stdlib only).
+
+    The home directory is read only where the platform needs it, and when it
+    cannot be determined (no HOME or USERPROFILE, as in a stripped-down service
+    environment) the system temp directory is used, so this never raises.
+    """
+    if sys.platform == "win32":
+        local = os.environ.get("LOCALAPPDATA")
+        if local:
+            return Path(local)
+    elif sys.platform != "darwin":
+        xdg = os.environ.get("XDG_STATE_HOME")
+        # The XDG spec ignores a relative value.
+        if xdg and os.path.isabs(xdg):
+            return Path(xdg)
+    try:
+        home = Path.home()
+    except (RuntimeError, KeyError, OSError):
+        return Path(tempfile.gettempdir())
+    if sys.platform == "win32":
+        return home / "AppData" / "Local"
+    if sys.platform == "darwin":
+        return home / "Library" / "Logs"
+    return home / ".local" / "state"
+
+
+def default_log_dir() -> Path:
+    """Where the engine log, the crash log and logging.properties go.
+
+    ``ARCADEDB_LOG_DIR`` if set, else ``arcadedb/log`` under the
+    per-user state directory. Never the working directory.
+    """
+    override = os.environ.get(LOG_DIR_ENV)
+    if override:
+        return Path(os.path.abspath(os.path.expanduser(override)))
+    return state_base_dir() / "arcadedb" / "log"
+
+
+def render_logging_config(engine_text: str) -> str:
+    """The engine's logging config with the file log in ``logsDirectory``.
+
+    The jar's own file hard-codes ``./log/arcadedb.log``, which lands in the
+    working directory. The engine resolves ``${arcadedb.server.logsDirectory}``
+    in the pattern, and the argument that sets it is added by the caller.
+    """
+    lines = [
+        line
+        for line in engine_text.splitlines()
+        if not re.match(r"\s*java\.util\.logging\.FileHandler\.pattern\s*[=:]", line)
+    ]
+    lines.append(
+        "java.util.logging.FileHandler.pattern="
+        "${arcadedb.server.logsDirectory}/arcadedb.log"
+    )
+    return "\n".join(lines) + "\n"
+
+
+def usable_log_dir(log_dir: Path) -> Path:
+    """Create the log directory; return it, or a fresh directory under the system temp directory when it cannot be created or
+    written (a read-only home, for example), so that nothing is ever written to the working directory.
+    """
+    try:
+        log_dir.mkdir(parents=True, exist_ok=True)
+        if not os.access(log_dir, os.W_OK | os.X_OK):
+            raise OSError(f"{log_dir} is not writable")
+    except OSError as exc:
+        fallback = Path(tempfile.mkdtemp(prefix="arcadedb-log-"))
+        _LOGGER.warning(
+            "Cannot use %s for ArcadeDB logs (%s); using %s. Set %s to choose one.",
+            log_dir,
+            exc,
+            fallback,
+            LOG_DIR_ENV,
+        )
+        return fallback
+    return log_dir
+
+
+def write_logging_config(log_dir: Path, engine_text: str) -> None:
+    """Write ``logging.properties`` in ``log_dir`` (replaced atomically, and only when its text changed)."""
+    config = log_dir / LOGGING_CONFIG_NAME
+    rendered = render_logging_config(engine_text)
+    try:
+        if not config.exists() or config.read_text("iso-8859-1") != rendered:
+            tmp = log_dir / f"{LOGGING_CONFIG_NAME}.{os.getpid()}.tmp"
+            tmp.write_text(rendered, encoding="iso-8859-1", newline="\n")
+            os.replace(tmp, config)
+    except OSError as exc:
+        _LOGGER.warning("Cannot write %s: %s", config, exc)

src/arcadedb/_native/lib.py

@@ -7,6 +7,7 @@
 import threading
 from pathlib import Path
 
+from .. import _logdir
 from ..exceptions import ArcadeDBError
 
 _LIB_NAMES = {
@@ -29,6 +30,9 @@
 # ARCADEDB_NATIVE_EXEC_MANY: the rows of an insert_many chunk that JSON text cannot carry unchanged go in one crossing (arcadedb_n_exec_many), not one call each
 EXEC_MANY = os.environ.get("ARCADEDB_NATIVE_EXEC_MANY", "1") != "0"
 
+# the directory the engine log, logging.properties and the crash files go to (None until the library is loaded)
+LOG_DIR_USED = None
+
 _lock = threading.Lock()
 _lib = None
 _isolate = None
@@ -61,6 +65,32 @@ def __del__(self):
                 pass
 
 
+def _log_isolate_args(user_args, log_dir) -> list:
+    """The isolate arguments that put the engine log in ``log_dir``; each one the user already gave is left out (theirs wins).
+
+    The engine reads ``arcadedb.server.logsDirectory`` and ``java.util.logging.config.file`` when it first logs, and the log file it
+    opens by default is ``./log/arcadedb.log`` in the working directory. An isolate argument is in place before any Java code runs.
+    """
+    posix = Path(log_dir).as_posix()
+    args = []
+    if not any(a.startswith("-Darcadedb.server.logsDirectory=") for a in user_args):
+        args.append(f"-Darcadedb.server.logsDirectory={posix}")
+    if not any(a.startswith("-Djava.util.logging.config.file=") for a in user_args):
+        args.append(
+            f"-Djava.util.logging.config.file={posix}/{_logdir.LOGGING_CONFIG_NAME}"
+        )
+    return args
+
+
+def _prepare_logging(user_args) -> list:
+    """Create the log directory, write its logging.properties and return the isolate arguments for it (see :func:`_log_isolate_args`)."""
+    global LOG_DIR_USED
+    log_dir = _logdir.usable_log_dir(_logdir.default_log_dir())
+    _logdir.write_logging_config(log_dir, _logdir.NATIVE_ENGINE_LOG_PROPERTIES)
+    LOG_DIR_USED = log_dir
+    return _log_isolate_args(user_args, log_dir)
+
+
 def _check_cpu() -> None:
     """An image built for x86-64-v3 (AVX2, BMI2, FMA) needs them: fail with a clear error instead of SIGILL on an older CPU."""
     if sys.platform != "linux" or os.environ.get("ARCADEDB_NATIVE_SKIP_CPU_CHECK"):
@@ -112,9 +142,12 @@ def _load():
         ]
         lib.graal_create_isolate.restype = ctypes.c_int
         params = None
+        # run-time image options for the isolate (e.g. "-XX:InitialCollectionPolicy=Adaptive -XX:MaximumYoungGenerationSizePercent=20")
         iso_args = os.environ.get("ARCADEDB_NATIVE_ISOLATE_ARGS", "").split()
+        # the log directory: always set, so that nothing is written to the working directory (the same rule as the JVM build)
+        iso_args += _prepare_logging(iso_args)
         if iso_args:
-            # run-time image options for the isolate (e.g. "-XX:InitialCollectionPolicy=Adaptive -XX:MaximumYoungGenerationSizePercent=20")
+
             class _Params(ctypes.Structure):
                 _fields_ = [
                     ("version", ctypes.c_int),

src/arcadedb/jvm.py

@@ -8,12 +8,10 @@
 import glob
 import os
 import platform
-import re
 import shlex
 import shutil
 import signal
 import sys
-import tempfile
 import threading
 import zipfile
 from pathlib import Path
@@ -23,6 +21,12 @@
 import jpype.imports
 
 from . import aot as _aot
+from ._logdir import LOG_DIR_ENV as _LOG_DIR_ENV
+from ._logdir import LOGGING_CONFIG_NAME as _LOGGING_CONFIG_NAME
+from ._logdir import default_log_dir as _default_log_dir
+from ._logdir import render_logging_config as _render_logging_config
+from ._logdir import usable_log_dir as _usable_log_dir
+from ._logdir import write_logging_config as _write_logging_config
 from ._logging import get_logger
 from .exceptions import ArcadeDBError
 
@@ -48,8 +52,6 @@
 _JVM_INTERRUPT = None  # the `interrupt` the running JVM was started with
 _LOG_DIR_USED = None  # the log directory the running JVM was started with
 
-_LOG_DIR_ENV = "ARCADEDB_LOG_DIR"
-_LOGGING_CONFIG_NAME = "logging.properties"
 _ENGINE_LOG_RESOURCE = "arcadedb-log.properties"
 
 
@@ -697,45 +699,6 @@ def _dedupe_max_heap(args: list[str]) -> list[str]:
     return filtered
 
 
-def _state_base_dir() -> Path:
-    """Per-user base directory for state and logs, by platform (stdlib only).
-
-    The home directory is read only where the platform needs it, and when it
-    cannot be determined (no HOME or USERPROFILE, as in a stripped-down service
-    environment) the system temp directory is used, so this never raises.
-    """
-    if sys.platform == "win32":
-        local = os.environ.get("LOCALAPPDATA")
-        if local:
-            return Path(local)
-    elif sys.platform != "darwin":
-        xdg = os.environ.get("XDG_STATE_HOME")
-        # The XDG spec ignores a relative value.
-        if xdg and os.path.isabs(xdg):
-            return Path(xdg)
-    try:
-        home = Path.home()
-    except (RuntimeError, KeyError, OSError):
-        return Path(tempfile.gettempdir())
-    if sys.platform == "win32":
-        return home / "AppData" / "Local"
-    if sys.platform == "darwin":
-        return home / "Library" / "Logs"
-    return home / ".local" / "state"
-
-
-def _default_log_dir() -> Path:
-    """Where the engine log, the crash log and logging.properties go.
-
-    ``ARCADEDB_LOG_DIR`` if set, else ``arcadedb/log`` under the
-    per-user state directory. Never the working directory.
-    """
-    override = os.environ.get(_LOG_DIR_ENV)
-    if override:
-        return Path(os.path.abspath(os.path.expanduser(override)))
-    return _state_base_dir() / "arcadedb" / "log"
-
-
 def _read_engine_log_properties(jar_files: Iterable[str]) -> Optional[str]:
     """Read the engine's bundled ``arcadedb-log.properties`` from its jar."""
     for jar in sorted(jar_files, key=lambda j: "engine" not in os.path.basename(j)):
@@ -747,26 +710,6 @@ def _read_engine_log_properties(jar_files: Iterable[str]) -> Optional[str]:
     return None
 
 
-def _render_logging_config(engine_text: str) -> str:
-    """The engine's logging config with the file log in ``logsDirectory``.
-
-    The jar's own file hard-codes ``./log/arcadedb.log``, which lands in the
-    working directory. The engine resolves ``${arcadedb.server.logsDirectory}``
-    in the pattern, and the JVM argument that sets it is added in
-    ``_build_jvm_args``.
-    """
-    lines = [
-        line
-        for line in engine_text.splitlines()
-        if not re.match(r"\s*java\.util\.logging\.FileHandler\.pattern\s*[=:]", line)
-    ]
-    lines.append(
-        "java.util.logging.FileHandler.pattern="
-        "${arcadedb.server.logsDirectory}/arcadedb.log"
-    )
-    return "\n".join(lines) + "\n"
-
-
 def _prepare_log_dir(log_dir: Path, jar_files: Iterable[str]) -> Path:
     """Create the log directory and write its logging.properties.
 
@@ -775,32 +718,10 @@ def _prepare_log_dir(log_dir: Path, jar_files: Iterable[str]) -> Path:
     read-only home, for example), so that nothing is ever written to the
     working directory.
     """
-    try:
-        log_dir.mkdir(parents=True, exist_ok=True)
-        if not os.access(log_dir, os.W_OK | os.X_OK):
-            raise OSError(f"{log_dir} is not writable")
-    except OSError as exc:
-        fallback = Path(tempfile.mkdtemp(prefix="arcadedb-log-"))
-        _LOGGER.warning(
-            "Cannot use %s for ArcadeDB logs (%s); using %s. Set %s to choose one.",
-            log_dir,
-            exc,
-            fallback,
-            _LOG_DIR_ENV,
-        )
-        log_dir = fallback
-
+    log_dir = _usable_log_dir(log_dir)
     engine_text = _read_engine_log_properties(jar_files)
     if engine_text is not None:
-        config = log_dir / _LOGGING_CONFIG_NAME
-        rendered = _render_logging_config(engine_text)
-        try:
-            if not config.exists() or config.read_text("iso-8859-1") != rendered:
-                tmp = log_dir / f"{_LOGGING_CONFIG_NAME}.{os.getpid()}.tmp"
-                tmp.write_text(rendered, encoding="iso-8859-1", newline="\n")
-                os.replace(tmp, config)
-        except OSError as exc:
-            _LOGGER.warning("Cannot write %s: %s", config, exc)
+        _write_logging_config(log_dir, engine_text)
     return log_dir