diff --git a/CHANGELOG.md b/CHANGELOG.md index 256dd9736..67e8808ca 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -39,6 +39,8 @@ Status of the `main` branch. Changes prior to the next official version change w - Allow language server priorities to be configured in `serena_config.yml` (for auto-detection during project creation) - Add `python_basedpyright` as an alternative Python language server + - Java/JDTLS: bound initialization and required startup waits with one total deadline that leaves + time for shutdown and reports the current phase and latest language status before an outer tool timeout #1789 - Nix/nixd: support custom `ls_path` launchers and external JSON settings through `config_path` #1737 - Fix: Nix/nixd diagnostics now use published diagnostics instead of the unsupported `textDocument/diagnostic` request, which terminated nixd #1802 diff --git a/docs/02-usage/050_configuration.md b/docs/02-usage/050_configuration.md index 65b5e6ccc..87ca3aeeb 100644 --- a/docs/02-usage/050_configuration.md +++ b/docs/02-usage/050_configuration.md @@ -706,6 +706,7 @@ The following settings are supported for the Java language server: | `lombok_show_generated` | `true` | Show Lombok-generated methods (`getX/setX`, `builder()`, `equals/hashCode/toString`, `withX`, fluent accessors) in `find_symbol`, `get_symbols_overview` and the symbol-edit tools. Set to `false` to restore the previous JDTLS default and hide the synthetic methods (e.g. when `@Data` classes pollute the outline with too many getters/setters). Requires JDTLS commit `b2d8952` / `vscode-java >= 1.53.0`; the bundled default already meets this. | | `jdtls_xmx` | `3G` | Maximum heap size for the JDTLS server JVM. | | `jdtls_xms` | `100m` | Initial heap size for the JDTLS server JVM. | +| `startup_timeout` | `600` | Maximum total seconds for JDTLS startup, shared across initialization, IntelliCode command registration (vscode-java mode only), and `ServiceReady`. Serena caps this deadline below the outer tool timeout so it has time to stop JDTLS and report the current phase and latest language status. | | `intellicode_xmx` | `1G` | (vscode-java mode only) Maximum heap size for the IntelliCode embedded JVM. | | `intellicode_xms` | `100m` | (vscode-java mode only) Initial heap size for the IntelliCode embedded JVM. | diff --git a/src/solidlsp/language_servers/eclipse_jdtls.py b/src/solidlsp/language_servers/eclipse_jdtls.py index 94531a9a0..ddace67fa 100644 --- a/src/solidlsp/language_servers/eclipse_jdtls.py +++ b/src/solidlsp/language_servers/eclipse_jdtls.py @@ -6,6 +6,7 @@ import hashlib import json import logging +import math import os import pathlib import platform @@ -15,8 +16,8 @@ import threading from dataclasses import dataclass from pathlib import Path, PurePath -from time import sleep -from typing import Any +from time import monotonic, sleep +from typing import Any, Never from overrides import override @@ -145,6 +146,9 @@ class EclipseJDTLS(SolidLanguageServer): - jdtls_xms: Initial heap size for the JDTLS server JVM (default: "100m") - intellicode_xmx: Maximum heap size for the IntelliCode embedded JVM (default: "1G") - intellicode_xms: Initial heap size for the IntelliCode embedded JVM (default: "100m") + - startup_timeout: Maximum total seconds for JDTLS startup (default: 600). When a request + timeout is configured, Serena caps this deadline so JDTLS shutdown and error reporting + can complete before the outer tool timeout. - lombok_show_generated: Show Lombok-generated methods (getX/setX/builder()/...) in document symbols by sending java.symbols.includeGeneratedCode=true to JDTLS (default: true). Set to false for @Data-heavy projects where the extra getters/setters are noise. @@ -192,6 +196,7 @@ class EclipseJDTLS(SolidLanguageServer): jdtls_xms: "100m" # initial heap size for the JDTLS server JVM intellicode_xmx: "1G" # maximum heap size for the IntelliCode embedded JVM intellicode_xms: "100m" # initial heap size for the IntelliCode embedded JVM + startup_timeout: 600 # maximum total JDTLS startup time lombok_show_generated: true # show Lombok-generated methods in document symbols (default true) gradle_version: "8.14.2" vscode_java_version: "1.54.0-923" # also accepts pinned legacy "1.42.0-561" @@ -203,6 +208,9 @@ class EclipseJDTLS(SolidLanguageServer): ``` """ + STARTUP_TIMEOUT = 600.0 + STARTUP_SHUTDOWN_TIMEOUT = 5.0 + @classmethod def supports_implementation_request(cls) -> bool: return True @@ -221,6 +229,109 @@ def __init__(self, config: LanguageServerConfig, repository_root_path: str, soli self._service_ready_event = threading.Event() self._project_ready_event = threading.Event() self._intellicode_enable_command_available = threading.Event() + self._startup_phase = "not_started" + self._last_language_status: tuple[str | None, str | None] | None = None + self._effective_startup_timeout: float | None = None + self._startup_deadline: float | None = None + self._get_startup_timeout() # validate before a server process can be started + + def _get_startup_timeout(self) -> float: + """Return the configured maximum total seconds for JDTLS startup.""" + configured_timeout = self._custom_settings.get("startup_timeout", self.STARTUP_TIMEOUT) + try: + timeout = float(configured_timeout) + except (TypeError, ValueError) as exc: + raise SolidLSPException("java.startup_timeout must be a positive finite number") from exc + + if not math.isfinite(timeout) or timeout <= 0: + raise SolidLSPException("java.startup_timeout must be a positive finite number") + return timeout + + def _get_startup_shutdown_timeout(self) -> float: + """Return a shutdown allowance that fits within the language-server request budget.""" + request_timeout = self.request_timeout + if request_timeout is None or not math.isfinite(request_timeout): + return self.STARTUP_SHUTDOWN_TIMEOUT + if request_timeout <= 0: + raise SolidLSPException("JDTLS request timeout must be positive") + return min(self.STARTUP_SHUTDOWN_TIMEOUT, request_timeout / 2) + + def _get_effective_startup_timeout(self) -> float: + """Return the total startup budget after reserving time for shutdown and reporting.""" + configured_timeout = self._get_startup_timeout() + request_timeout = self.request_timeout + if request_timeout is None or not math.isfinite(request_timeout): + return configured_timeout + + shutdown_timeout = self._get_startup_shutdown_timeout() + # Serena sets the LS request timeout five seconds below the outer tool timeout. Reserving + # shutdown time here leaves that existing five-second gap for propagating the detailed error. + return min(configured_timeout, request_timeout - shutdown_timeout) + + def _begin_startup_deadline(self) -> None: + timeout = self._get_effective_startup_timeout() + self._effective_startup_timeout = timeout + self._startup_deadline = monotonic() + timeout + log.info("JDTLS startup deadline: %g seconds total", timeout) + + def _remaining_startup_time(self) -> float: + if self._startup_deadline is None: + raise RuntimeError("JDTLS startup deadline has not been initialized") + return max(0.0, self._startup_deadline - monotonic()) + + def _set_startup_phase(self, phase: str) -> None: + self._startup_phase = phase + log.info("JDTLS startup phase: %s", phase) + + def _handle_language_status(self, params: dict) -> None: + log.info("Language status update: %s", params) + status_type = params.get("type") + status_message = params.get("message") + self._last_language_status = (status_type, status_message) + + if status_type == "ServiceReady" and status_message == "ServiceReady": + self._service_ready_event.set() + if status_type == "ProjectStatus" and status_message == "OK": + self._project_ready_event.set() + + def _describe_last_language_status(self) -> str: + if self._last_language_status is None: + return "none received" + status_type, status_message = self._last_language_status + return f"type={status_type!r}, message={status_message!r}" + + def _raise_startup_timeout(self, wait_name: str, cause: BaseException | None = None) -> Never: + phase = self._startup_phase + timeout = self._effective_startup_timeout + if timeout is None: + raise RuntimeError("JDTLS startup deadline has not been initialized") + message = ( + f"JDTLS startup timed out after {timeout:g} seconds total while waiting for {wait_name} " + f"(phase={phase}, last_language_status={self._describe_last_language_status()})" + ) + log.error(message) + self.stop(shutdown_timeout=self._get_startup_shutdown_timeout()) + error = SolidLSPException(message) + if cause is None: + raise error + raise error from cause + + def _set_startup_request_timeout(self, wait_name: str) -> None: + remaining = self._remaining_startup_time() + if remaining <= 0: + self._raise_startup_timeout(wait_name) + self.server.set_request_timeout(remaining) + + def _wait_for_startup_signal(self, event: threading.Event, signal_name: str) -> None: + phase = f"waiting_for_{signal_name}" + self._set_startup_phase(phase) + remaining = self._remaining_startup_time() + log.info("Waiting up to %g remaining seconds for JDTLS %s", remaining, signal_name) + + if event.wait(timeout=remaining): + self._set_startup_phase(f"{signal_name}_received") + return + self._raise_startup_timeout(signal_name) def _create_dependency_provider(self) -> LanguageServerDependencyProvider: ls_resources_dir = self.ls_resources_dir(self._solidlsp_settings) @@ -1383,14 +1494,6 @@ def register_capability_handler(params: dict) -> None: self._intellicode_enable_command_available.set() return - def lang_status_handler(params: dict) -> None: - log.info("Language status update: %s", params) - if params["type"] == "ServiceReady" and params["message"] == "ServiceReady": - self._service_ready_event.set() - if params["type"] == "ProjectStatus": - if params["message"] == "OK": - self._project_ready_event.set() - def execute_client_command_handler(params: dict) -> list: assert params["command"] == "_java.reloadBundles.command" assert params["arguments"] == [] @@ -1402,61 +1505,79 @@ def window_log_message(msg: dict) -> None: def do_nothing(params: dict) -> None: return - self.server.on_request("client/registerCapability", register_capability_handler) - self.server.on_notification("language/status", lang_status_handler) - self.server.on_notification("window/logMessage", window_log_message) - self.server.on_request("workspace/executeClientCommand", execute_client_command_handler) - self.server.on_notification("$/progress", do_nothing) - self.server.on_notification("textDocument/publishDiagnostics", do_nothing) - self.server.on_notification("language/actionableNotification", do_nothing) - - log.info("Starting EclipseJDTLS server process") - self.server.start() - initialize_params = self._create_initialize_params() - - log.info("Sending initialize request from LSP client to LSP server and awaiting response") - init_response = self.server.send.initialize(initialize_params) - assert init_response["capabilities"]["textDocumentSync"]["change"] == 2 # type: ignore - assert "completionProvider" not in init_response["capabilities"] - assert "executeCommandProvider" not in init_response["capabilities"] - - self.server.notify.initialized({}) - - self.server.notify.workspace_did_change_configuration({"settings": initialize_params["initializationOptions"]["settings"]}) # type: ignore - - # IntelliCode enablement is only relevant in the default vscode-java VSIX mode where the - # IntelliCode bundle is shipped. In upstream-jdtls mode it's absent and the - # 'java.intellicode.enable' command will never be registered, so we skip the wait/call. - if self.runtime_dependency_paths.intellicode_jar_path is not None: - self._intellicode_enable_command_available.wait() - - java_intellisense_members_path = self.runtime_dependency_paths.intellisense_members_path - assert java_intellisense_members_path is not None - assert os.path.exists(java_intellisense_members_path) - intellicode_enable_result = self.server.send.execute_command( - { - "command": "java.intellicode.enable", - "arguments": [True, java_intellisense_members_path], - } - ) - assert intellicode_enable_result - - if not self._service_ready_event.is_set(): - log.info("Waiting for service to be ready ...") - self._service_ready_event.wait() - log.info("Service is ready") + original_request_timeout = self.request_timeout + self._begin_startup_deadline() + try: + self.server.on_request("client/registerCapability", register_capability_handler) + self.server.on_notification("language/status", self._handle_language_status) + self.server.on_notification("window/logMessage", window_log_message) + self.server.on_request("workspace/executeClientCommand", execute_client_command_handler) + self.server.on_notification("$/progress", do_nothing) + self.server.on_notification("textDocument/publishDiagnostics", do_nothing) + self.server.on_notification("language/actionableNotification", do_nothing) + + self._set_startup_phase("starting_process") + self.server.start() + initialize_params = self._create_initialize_params() + + self._set_startup_phase("waiting_for_initialize_response") + self._set_startup_request_timeout("initialize_response") + try: + init_response = self.server.send.initialize(initialize_params) + except TimeoutError as exc: + self._raise_startup_timeout("initialize_response", cause=exc) + assert init_response["capabilities"]["textDocumentSync"]["change"] == 2 # type: ignore + assert "completionProvider" not in init_response["capabilities"] + assert "executeCommandProvider" not in init_response["capabilities"] + + self.server.notify.initialized({}) + + initialization_options = initialize_params["initializationOptions"] + assert isinstance(initialization_options, dict) + self.server.notify.workspace_did_change_configuration({"settings": initialization_options["settings"]}) + + # IntelliCode enablement is only relevant in the default vscode-java VSIX mode where the + # IntelliCode bundle is shipped. In upstream-jdtls mode it's absent and the + # 'java.intellicode.enable' command will never be registered, so we skip the wait/call. + if self.runtime_dependency_paths.intellicode_jar_path is not None: + self._wait_for_startup_signal( + self._intellicode_enable_command_available, + "intellicode_command_registration", + ) - if not self._project_ready_event.is_set(): - log.info("Waiting for project to be ready ...") - project_ready_timeout = 20 # Hotfix: Using timeout until we figure out why sometimes we don't get the project ready event - if self._project_ready_event.wait(timeout=project_ready_timeout): - log.info("Project is ready") + java_intellisense_members_path = self.runtime_dependency_paths.intellisense_members_path + assert java_intellisense_members_path is not None + assert os.path.exists(java_intellisense_members_path) + self._set_startup_phase("waiting_for_intellicode_enable_response") + self._set_startup_request_timeout("intellicode_enable_response") + try: + intellicode_enable_result = self.server.send.execute_command( + { + "command": "java.intellicode.enable", + "arguments": [True, java_intellisense_members_path], + } + ) + except TimeoutError as exc: + self._raise_startup_timeout("intellicode_enable_response", cause=exc) + assert intellicode_enable_result + self._set_startup_phase("intellicode_enabled") + + self._wait_for_startup_signal(self._service_ready_event, "service_ready") + + if not self._project_ready_event.is_set(): + self._set_startup_phase("waiting_for_project_status") + project_ready_timeout = min(20.0, self._remaining_startup_time()) + log.info("Waiting up to %g seconds for project to be ready ...", project_ready_timeout) + if project_ready_timeout > 0 and self._project_ready_event.wait(timeout=project_ready_timeout): + log.info("Project is ready") + else: + log.warning("Did not receive project ready status before the startup deadline; proceeding anyway") else: - log.warning("Did not receive project ready status within %d seconds; proceeding anyway", project_ready_timeout) - else: - log.info("Project is ready") + log.info("Project is ready") - log.info("Startup complete") + self._set_startup_phase("complete") + finally: + self.server.set_request_timeout(original_request_timeout) @override def _request_hover(self, file_buffer: LSPFileBuffer, line: int, column: int) -> ls_types.Hover | None: diff --git a/src/solidlsp/ls.py b/src/solidlsp/ls.py index d0706a720..1a3d1561a 100644 --- a/src/solidlsp/ls.py +++ b/src/solidlsp/ls.py @@ -562,6 +562,7 @@ def __init__( self._load_document_symbols_cache() self.server_started = False + self._request_timeout: float | None = None if config.trace_lsp_communication: def logging_fn(source: str, target: str, msg: StringDict | str) -> None: @@ -1183,8 +1184,14 @@ def set_request_timeout(self, timeout: float | None) -> None: """ :param timeout: the timeout, in seconds, for requests to the language server. """ + self._request_timeout = timeout self.server.set_request_timeout(timeout) + @property + def request_timeout(self) -> float | None: + """Return the configured timeout for requests to the language server.""" + return self._request_timeout + def get_ignore_spec(self) -> pathspec.PathSpec: """ Returns the pathspec matcher for the paths that were configured to be ignored through diff --git a/test/solidlsp/java/test_jdtls_startup_timeout.py b/test/solidlsp/java/test_jdtls_startup_timeout.py new file mode 100644 index 000000000..256dc7826 --- /dev/null +++ b/test/solidlsp/java/test_jdtls_startup_timeout.py @@ -0,0 +1,218 @@ +"""Unit tests for bounded Eclipse JDTLS startup waits.""" + +import threading +from types import SimpleNamespace +from typing import Any, cast + +import pytest + +from serena.task_executor import TaskExecutor +from serena.tools.tools_base import Tool, ToolMarkerDoesNotRequireActiveProject +from solidlsp.language_servers import eclipse_jdtls as eclipse_jdtls_module +from solidlsp.language_servers.eclipse_jdtls import EclipseJDTLS +from solidlsp.ls_exceptions import SolidLSPException +from solidlsp.settings import SolidLSPSettings + + +class _FakeProtocolServer: + def __init__(self, stop_error: Exception | None = None) -> None: + self.stop_calls: list[float] = [] + self.request_timeouts: list[float | None] = [] + self.stop_error = stop_error + + def set_request_timeout(self, timeout: float | None) -> None: + self.request_timeouts.append(timeout) + + def stop(self, timeout: float = 5.0) -> None: + self.stop_calls.append(timeout) + if self.stop_error is not None: + raise self.stop_error + + +def _bare_jdtls( + custom_settings: dict | None = None, + *, + request_timeout: float | None = None, + stop_error: Exception | None = None, +) -> tuple[EclipseJDTLS, _FakeProtocolServer]: + """Build only the state touched by the startup timeout helpers.""" + server = object.__new__(EclipseJDTLS) + server._custom_settings = SolidLSPSettings.CustomLSSettings(custom_settings) + server._service_ready_event = threading.Event() + server._project_ready_event = threading.Event() + server._intellicode_enable_command_available = threading.Event() + server._startup_phase = "not_started" + server._last_language_status = None + server._effective_startup_timeout = None + server._startup_deadline = None + server._request_timeout = None + protocol_server = _FakeProtocolServer(stop_error) + server.server = cast(Any, protocol_server) + server.server_started = True + server.set_request_timeout(request_timeout) + return server, protocol_server + + +def test_startup_timeout_default_and_override() -> None: + server, _ = _bare_jdtls() + assert server._get_startup_timeout() == 600.0 + + server, _ = _bare_jdtls({"startup_timeout": 12.5}) + assert server._get_startup_timeout() == 12.5 + + +def test_startup_timeout_is_capped_below_outer_tool_budget() -> None: + # Serena derives this 595-second LS request timeout from a 600-second outer tool timeout. + server, protocol_server = _bare_jdtls(request_timeout=595) + + assert protocol_server.request_timeouts == [595] + assert server._get_startup_shutdown_timeout() == 5 + assert server._get_effective_startup_timeout() == 590 + + +@pytest.mark.parametrize("configured_timeout", [0, -1, "invalid", float("inf"), float("nan")]) +def test_startup_timeout_must_be_positive_and_finite(configured_timeout: object) -> None: + server, _ = _bare_jdtls({"startup_timeout": configured_timeout}) + + with pytest.raises(SolidLSPException, match="positive finite number"): + server._get_startup_timeout() + + +def test_language_status_handler_tracks_latest_status_and_sets_events() -> None: + server, _ = _bare_jdtls() + + server._handle_language_status({"type": "ProjectStatus", "message": "OK"}) + assert server._project_ready_event.is_set() + assert not server._service_ready_event.is_set() + assert server._describe_last_language_status() == "type='ProjectStatus', message='OK'" + + server._handle_language_status({"type": "ServiceReady", "message": "ServiceReady"}) + assert server._service_ready_event.is_set() + assert server._describe_last_language_status() == "type='ServiceReady', message='ServiceReady'" + + +def test_received_startup_signal_does_not_stop_server() -> None: + server, protocol_server = _bare_jdtls({"startup_timeout": 1}) + event = threading.Event() + event.set() + + server._begin_startup_deadline() + server._wait_for_startup_signal(event, "service_ready") + + assert server._startup_phase == "service_ready_received" + assert protocol_server.stop_calls == [] + assert server.server_started + + +def test_startup_timeout_reports_phase_and_last_status_then_stops_server() -> None: + server, protocol_server = _bare_jdtls({"startup_timeout": 0.001}) + server._handle_language_status({"type": "ProjectStatus", "message": "Starting"}) + + server._begin_startup_deadline() + with pytest.raises(SolidLSPException) as exc_info: + server._wait_for_startup_signal(threading.Event(), "service_ready") + + message = str(exc_info.value) + assert "after 0.001 seconds total" in message + assert "waiting for service_ready" in message + assert "phase=waiting_for_service_ready" in message + assert "last_language_status=type='ProjectStatus', message='Starting'" in message + assert protocol_server.stop_calls == [5.0] + assert not server.server_started + + +def test_shutdown_error_does_not_hide_startup_timeout() -> None: + server, protocol_server = _bare_jdtls( + {"startup_timeout": 0.001}, + stop_error=RuntimeError("shutdown failed"), + ) + + server._begin_startup_deadline() + with pytest.raises(SolidLSPException, match="waiting for intellicode_command_registration"): + server._wait_for_startup_signal(threading.Event(), "intellicode_command_registration") + + assert protocol_server.stop_calls == [5.0] + assert not server.server_started + + +class _AdvancingEvent: + def __init__(self, clock: list[float], elapsed: float) -> None: + self.clock = clock + self.elapsed = elapsed + self.wait_timeouts: list[float | None] = [] + + def wait(self, timeout: float | None = None) -> bool: + self.wait_timeouts.append(timeout) + self.clock[0] += self.elapsed + return timeout is None or self.elapsed <= timeout + + +def test_required_signals_share_one_total_startup_deadline(monkeypatch: pytest.MonkeyPatch) -> None: + clock = [100.0] + monkeypatch.setattr(eclipse_jdtls_module, "monotonic", lambda: clock[0]) + server, _ = _bare_jdtls({"startup_timeout": 10}) + first_signal = _AdvancingEvent(clock, elapsed=6) + second_signal = _AdvancingEvent(clock, elapsed=1) + + server._begin_startup_deadline() + server._wait_for_startup_signal(cast(Any, first_signal), "intellicode_command_registration") + server._wait_for_startup_signal(cast(Any, second_signal), "service_ready") + + assert first_signal.wait_timeouts == [10] + assert second_signal.wait_timeouts == [4] + + +def test_startup_requests_use_remaining_total_deadline(monkeypatch: pytest.MonkeyPatch) -> None: + clock = [100.0] + monkeypatch.setattr(eclipse_jdtls_module, "monotonic", lambda: clock[0]) + server, protocol_server = _bare_jdtls(request_timeout=595) + + server._begin_startup_deadline() + clock[0] += 10 + server._set_startup_request_timeout("initialize_response") + + assert protocol_server.request_timeouts == [595, 580] + + +class _FakeAgent: + def __init__(self, tool_timeout: float) -> None: + self.serena_config = SimpleNamespace(tool_timeout=tool_timeout) + self._task_executor = TaskExecutor("JDTLSStartupTimeoutRegression") + + def tool_is_active(self, tool_name: str) -> bool: + return True + + def issue_task(self, task, name: str | None = None, logged: bool = True, timeout: float | None = None): + return self._task_executor.issue_task(task, name=name, logged=logged, timeout=timeout) + + def record_tool_usage(self, apply_kwargs: dict, result: str, tool: Tool) -> None: + pass + + def get_language_server_manager(self): + return None + + +class _StartupWaitTool(Tool, ToolMarkerDoesNotRequireActiveProject): + def __init__(self, agent: _FakeAgent, server: EclipseJDTLS) -> None: + super().__init__(cast(Any, agent)) + self.server = server + + def apply(self) -> str: + """Wait for a deliberately absent JDTLS startup signal.""" + self.server._begin_startup_deadline() + self.server._wait_for_startup_signal(threading.Event(), "service_ready") + raise AssertionError("The startup wait should have timed out") + + +def test_detailed_startup_error_surfaces_before_generic_tool_timeout() -> None: + server, protocol_server = _bare_jdtls({"startup_timeout": 10}, request_timeout=0.2) + server.STARTUP_SHUTDOWN_TIMEOUT = 0.05 + tool = _StartupWaitTool(_FakeAgent(tool_timeout=0.6), server) + + result = tool.apply_ex(log_call=False) + + assert "SolidLSPException: JDTLS startup timed out after 0.15 seconds total" in result + assert "phase=waiting_for_service_ready" in result + assert "last_language_status=none received" in result + assert "Tool execution timed out" not in result + assert protocol_server.stop_calls == [0.05]