diff --git a/src/compile/compilation.cpp b/src/compile/compilation.cpp index ffc5bf386..0b8569825 100644 --- a/src/compile/compilation.cpp +++ b/src/compile/compilation.cpp @@ -242,6 +242,7 @@ CompilationStatus CompilationUnitRef::Self::run_clang( std::unique_ptr diagnostic_consumer = self.create_diagnostic(); std::unique_ptr invocation = self.create_invocation(params, diagnostic_consumer.get()); if(!invocation) { + LOG_WARN("run_clang: invocation creation failed"); return CompilationStatus::SetupFail; } @@ -256,6 +257,7 @@ CompilationStatus CompilationUnitRef::Self::run_clang( } if(!instance.createTarget()) { + LOG_WARN("run_clang: target creation failed"); return CompilationStatus::SetupFail; } @@ -270,6 +272,7 @@ CompilationStatus CompilationUnitRef::Self::run_clang( /// But if we fail to `BeginSourceFile` we don't need to call `EndSourceFile`. So just /// reset it. self.action.reset(); + LOG_WARN("run_clang: BeginSourceFile failed"); return CompilationStatus::SetupFail; } @@ -303,6 +306,8 @@ CompilationStatus CompilationUnitRef::Self::run_clang( /// in crash frequently. So forbidden it here and return as error. if(!instance.getFrontendOpts().OutputFile.empty() && instance.getDiagnostics().hasErrorOccurred()) { + LOG_WARN("run_clang: errors during PCH/PCM generation, output={}", + instance.getFrontendOpts().OutputFile); return CompilationStatus::FatalError; } diff --git a/src/server/compiler.cpp b/src/server/compiler.cpp index 0686049b4..5f3f33cf3 100644 --- a/src/server/compiler.cpp +++ b/src/server/compiler.cpp @@ -122,9 +122,11 @@ void Compiler::init_compile_graph() { auto result = co_await pool.send_stateless(bp); if(!result.has_value() || !result.value().success) { - LOG_WARN("BuildPCM failed for module {}: {}", - mod_it->second, - result.has_value() ? result.value().error : result.error().message); + auto error_msg = result.has_value() ? result.value().error : result.error().message; + LOG_WARN("BuildPCM failed for module {}: {}", mod_it->second, error_msg); + peer.send_notification(protocol::LogMessageParams{ + protocol::MessageType::Warning, + std::format("PCM build failed for module {}: {}", mod_it->second, error_msg)}); co_return false; } @@ -171,6 +173,10 @@ bool Compiler::fill_compile_args(llvm::StringRef path, auto& cmd = results.front(); directory = cmd.resolved.directory.str(); arguments = cmd.to_string_argv(); + LOG_DEBUG("fill_compile_args: CDB match for {} (dir={}, {} args)", + path, + directory, + arguments.size()); return true; } @@ -521,9 +527,11 @@ kota::task Compiler::ensure_pch(Session& session, auto result = co_await pool.send_stateless(bp); if(!result.has_value() || !result.value().success) { - LOG_WARN("PCH build failed for {}: {}", - path, - result.has_value() ? result.value().error : result.error().message); + auto error_msg = result.has_value() ? result.value().error : result.error().message; + LOG_WARN("PCH build failed for {}: {}", path, error_msg); + peer.send_notification(protocol::LogMessageParams{ + protocol::MessageType::Warning, + std::format("PCH build failed for {}: {}", path, error_msg)}); workspace.pch_cache[path_id].building.reset(); completion->set(); co_return false; @@ -730,6 +738,10 @@ kota::task Compiler::ensure_compiled(Session& session) { params.version = sess->version; params.text = sess->text; if(!self->fill_compile_args(file_path, params.directory, params.arguments, sess)) { + LOG_WARN("ensure_compiled: no compile args for {}", uri_str); + self->peer.send_notification(protocol::LogMessageParams{ + protocol::MessageType::Warning, + std::format("No compile arguments available for {}", file_path)}); finish_compile(); co_return; } @@ -737,6 +749,9 @@ kota::task Compiler::ensure_compiled(Session& session) { if(!co_await self ->ensure_deps(*sess, params.directory, params.arguments, params.pch, params.pcms)) { LOG_WARN("Dependency preparation failed for {}, skipping compile", uri_str); + self->peer.send_notification(protocol::LogMessageParams{ + protocol::MessageType::Warning, + std::format("Dependency preparation failed for {}", file_path)}); finish_compile(); co_return; } @@ -768,6 +783,9 @@ kota::task Compiler::ensure_compiled(Session& session) { if(!result.has_value()) { LOG_WARN("Compile failed for {}: {}", uri_str, result.error().message); + self->peer.send_notification(protocol::LogMessageParams{ + protocol::MessageType::Error, + std::format("Compilation failed for {}: {}", file_path, result.error().message)}); self->clear_diagnostics(uri_str); finish_compile(); co_return; @@ -816,11 +834,17 @@ Compiler::RawResult Compiler::forward_query(worker::QueryKind kind, auto text = session.text; if(!co_await ensure_compiled(session)) { - co_return serde_raw{"null"}; + LOG_WARN("forward_query: compilation failed for {}", path); + co_await kota::fail("Compilation failed"); } auto sit = sessions.find(path_id); - if(sit == sessions.end() || sit->second.ast_dirty) { + if(sit == sessions.end()) { + LOG_WARN("forward_query: session lost after compile for {}", path); + co_await kota::fail("Document was closed during compilation"); + } + if(sit->second.ast_dirty) { + LOG_DEBUG("forward_query: still dirty after compile for {} (concurrent edit)", path); co_return serde_raw{"null"}; } @@ -832,8 +856,13 @@ Compiler::RawResult Compiler::forward_query(worker::QueryKind kind, if(position) { auto offset = mapper.to_offset(*position); - if(!offset) - co_return serde_raw{"null"}; + if(!offset) { + LOG_WARN("forward_query: invalid position {}:{} for {}", + position->line, + position->character, + path); + co_await kota::fail("Invalid position: failed to convert to byte offset"); + } wp.offset = *offset; } @@ -847,7 +876,8 @@ Compiler::RawResult Compiler::forward_query(worker::QueryKind kind, auto result = co_await pool.send_stateful(path_id, wp); if(!result.has_value()) { - co_return serde_raw{}; + LOG_WARN("forward_query: worker failed for {}: {}", path, result.error().message); + co_await kota::fail(result.error().message); } co_return std::move(result.value()); } @@ -866,27 +896,36 @@ Compiler::RawResult Compiler::forward_build(worker::BuildKind kind, wp.version = session.version; wp.text = session.text; if(!fill_compile_args(path, wp.directory, wp.arguments, &session)) { - co_return serde_raw{}; + LOG_WARN("forward_build: compile args not available for {}", path); + co_await kota::fail("Compile arguments not available"); } if(!co_await ensure_deps(session, wp.directory, wp.arguments, wp.pch, wp.pcms)) { - co_return serde_raw{}; + LOG_WARN("forward_build: dependency preparation failed for {}", path); + co_await kota::fail("Dependency preparation failed"); } // After co_await, verify session still exists. if(sessions.find(path_id) == sessions.end()) { - co_return serde_raw{}; + LOG_WARN("forward_build: session lost after co_await for {}", path); + co_await kota::fail("Document was closed during compilation"); } lsp::PositionMapper mapper(wp.text, lsp::PositionEncoding::UTF16); auto offset = mapper.to_offset(position); - if(!offset) - co_return serde_raw{"null"}; + if(!offset) { + LOG_WARN("forward_build: invalid position {}:{} for {}", + position.line, + position.character, + path); + co_await kota::fail("Invalid position: failed to convert to byte offset"); + } wp.offset = *offset; auto result = co_await pool.send_stateless(wp); if(!result.has_value()) { - co_return serde_raw{}; + LOG_WARN("forward_build: worker failed for {}: {}", path, result.error().message); + co_await kota::fail(result.error().message); } co_return std::move(result.value().result_json); } @@ -904,8 +943,10 @@ Compiler::RawResult Compiler::handle_completion(const protocol::Position& positi pctx.kind == CompletionContext::IncludeAngled) { std::string directory; std::vector arguments; - if(!fill_compile_args(path, directory, arguments)) - co_return serde_raw{"[]"}; + if(!fill_compile_args(path, directory, arguments)) { + LOG_WARN("handle_completion: compile args not available for {}", path); + co_await kota::fail("Compile arguments not available for include completion"); + } std::vector args_ptrs; args_ptrs.reserve(arguments.size()); diff --git a/src/server/config.cpp b/src/server/config.cpp index ed767be23..c1798a097 100644 --- a/src/server/config.cpp +++ b/src/server/config.cpp @@ -168,7 +168,7 @@ std::optional Config::load_from_json(llvm::StringRef json, llvm::StringR return config; } -Config Config::load_from_workspace(llvm::StringRef workspace_root) { +Config Config::load_from_workspace(llvm::StringRef workspace_root, std::string* warning) { if(!workspace_root.empty()) { for(auto* name: {"clice.toml", ".clice/config.toml"}) { auto config_path = path::join(workspace_root, name); @@ -179,6 +179,9 @@ Config Config::load_from_workspace(llvm::StringRef workspace_root) { // Present but malformed: fall through to defaults, but surface // the situation clearly so users know their config wasn't applied. LOG_WARN("Falling back to default configuration because {} is invalid", config_path); + if(warning) + *warning = std::format("Configuration file {} is invalid, falling back to defaults", + config_path); } } diff --git a/src/server/config.h b/src/server/config.h index 6d398491c..46afe5ae8 100644 --- a/src/server/config.h +++ b/src/server/config.h @@ -73,7 +73,10 @@ struct Config { /// Load config from the workspace, trying standard locations. /// Returns a default config (with apply_defaults) if no file is found. - static Config load_from_workspace(llvm::StringRef workspace_root); + /// If `warning` is non-null and a config file was found but malformed, + /// the warning message is written there. + static Config load_from_workspace(llvm::StringRef workspace_root, + std::string* warning = nullptr); }; } // namespace clice diff --git a/src/server/master_server.cpp b/src/server/master_server.cpp index 6255cec6f..8218b37fe 100644 --- a/src/server/master_server.cpp +++ b/src/server/master_server.cpp @@ -125,6 +125,9 @@ void MasterServer::load_workspace() { if(cdb_path.empty()) { LOG_WARN("No compile_commands.json found in workspace {}", workspace_root); + peer.send_notification(protocol::LogMessageParams{ + protocol::MessageType::Warning, + std::format("No compile_commands.json found in workspace {}", workspace_root)}); return; } @@ -283,10 +286,18 @@ void MasterServer::register_handlers() { // any initializationOptions on top so fields not mentioned in the JSON // keep the values from clice.toml — kotatsu's deserializer only touches // fields that are present in the input. - workspace.config = Config::load_from_workspace(workspace_root); + std::string config_warning; + workspace.config = Config::load_from_workspace(workspace_root, &config_warning); + if(!config_warning.empty()) + peer.send_notification( + protocol::LogMessageParams{protocol::MessageType::Warning, config_warning}); if(!init_options_json.empty()) { if(auto ov = kota::codec::json::parse(init_options_json, workspace.config); !ov) { LOG_WARN("Failed to apply initializationOptions: {}", ov.error().to_string()); + peer.send_notification(protocol::LogMessageParams{ + protocol::MessageType::Warning, + std::format("Failed to apply initializationOptions: {}", + ov.error().to_string())}); } else { // Re-run apply_defaults so overridden strings get workspace // substitution and `compiled_rules` is rebuilt if `rules` @@ -322,6 +333,8 @@ void MasterServer::register_handlers() { pool_opts.log_dir = session_log_dir; if(!pool.start(pool_opts)) { LOG_ERROR("Failed to start worker pool"); + peer.send_notification(protocol::LogMessageParams{protocol::MessageType::Error, + "Failed to start worker pool"}); return; } @@ -488,7 +501,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); co_return co_await compiler.forward_query(worker::QueryKind::Hover, sit->second, params.text_document_position_params.position); @@ -500,7 +513,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); co_return co_await compiler.forward_query(worker::QueryKind::SemanticTokens, sit->second); }); @@ -510,7 +523,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); co_return co_await compiler.forward_query(worker::QueryKind::InlayHints, sit->second, {}, @@ -523,7 +536,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); co_return co_await compiler.forward_query(worker::QueryKind::FoldingRange, sit->second); }); @@ -533,7 +546,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); co_return co_await compiler.forward_query(worker::QueryKind::DocumentSymbol, sit->second); }); @@ -543,7 +556,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); auto& session = sit->second; auto result = co_await compiler.forward_query(worker::QueryKind::DocumentLink, session); if(!result.has_value()) @@ -576,7 +589,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); co_return co_await compiler.forward_query(worker::QueryKind::CodeAction, sit->second); }); @@ -631,7 +644,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); co_return co_await compiler.forward_query(worker::QueryKind::GoToDefinition, sit->second, pos); @@ -679,7 +692,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); auto pause = indexer.scoped_pause(); auto result = co_await compiler.handle_completion(params.text_document_position_params.position, @@ -693,7 +706,7 @@ void MasterServer::register_handlers() { auto path_id = workspace.path_pool.intern(path); auto sit = sessions.find(path_id); if(sit == sessions.end()) - co_return serde_raw{"null"}; + co_await kota::fail("Document not open"); auto pause = indexer.scoped_pause(); auto result = co_await compiler.forward_build(worker::BuildKind::SignatureHelp, params.text_document_position_params.position, @@ -725,10 +738,8 @@ void MasterServer::register_handlers() { const protocol::CallHierarchyIncomingCallsParams& params) -> RawResult { auto info = resolve_item(params.item.uri, params.item.range, params.item.data); if(!info) - co_return serde_raw{"null"}; + co_await kota::fail("Failed to resolve call hierarchy item"); auto results = indexer.find_incoming_calls(info->hash); - if(results.empty()) - co_return serde_raw{"null"}; co_return to_raw(results); }); @@ -737,10 +748,8 @@ void MasterServer::register_handlers() { const protocol::CallHierarchyOutgoingCallsParams& params) -> RawResult { auto info = resolve_item(params.item.uri, params.item.range, params.item.data); if(!info) - co_return serde_raw{"null"}; + co_await kota::fail("Failed to resolve call hierarchy item"); auto results = indexer.find_outgoing_calls(info->hash); - if(results.empty()) - co_return serde_raw{"null"}; co_return to_raw(results); }); @@ -767,10 +776,8 @@ void MasterServer::register_handlers() { const protocol::TypeHierarchySupertypesParams& params) -> RawResult { auto info = resolve_item(params.item.uri, params.item.range, params.item.data); if(!info) - co_return serde_raw{"null"}; + co_await kota::fail("Failed to resolve type hierarchy item"); auto results = indexer.find_supertypes(info->hash); - if(results.empty()) - co_return serde_raw{"null"}; co_return to_raw(results); }); @@ -779,18 +786,14 @@ void MasterServer::register_handlers() { const protocol::TypeHierarchySubtypesParams& params) -> RawResult { auto info = resolve_item(params.item.uri, params.item.range, params.item.data); if(!info) - co_return serde_raw{"null"}; + co_await kota::fail("Failed to resolve type hierarchy item"); auto results = indexer.find_subtypes(info->hash); - if(results.empty()) - co_return serde_raw{"null"}; co_return to_raw(results); }); peer.on_request( [this](RequestContext& ctx, const protocol::WorkspaceSymbolParams& params) -> RawResult { auto results = indexer.search_symbols(params.query); - if(results.empty()) - co_return serde_raw{"null"}; co_return to_raw(results); }); diff --git a/src/server/stateful_worker.cpp b/src/server/stateful_worker.cpp index 8337a0eab..d966d8672 100644 --- a/src/server/stateful_worker.cpp +++ b/src/server/stateful_worker.cpp @@ -94,6 +94,7 @@ class StatefulWorker { kota::task with_ast(llvm::StringRef path, F&& fn) { auto it = documents.find(path); if(it == documents.end()) { + LOG_WARN("with_ast: document not found: {}", path.str()); co_return kota::codec::RawValue{"null"}; } @@ -105,8 +106,10 @@ class StatefulWorker { co_await doc->strand.lock(); auto result = co_await kota::queue([&]() -> kota::codec::RawValue { - if(!doc->has_ast || (!doc->unit.completed() && !doc->unit.fatal_error())) + if(!doc->has_ast || (!doc->unit.completed() && !doc->unit.fatal_error())) { + LOG_WARN("with_ast: AST not available for {}", path.str()); return kota::codec::RawValue{"null"}; + } return fn(*doc); }); diff --git a/src/server/stateless_worker.cpp b/src/server/stateless_worker.cpp index 7d85f8fcf..9406fab18 100644 --- a/src/server/stateless_worker.cpp +++ b/src/server/stateless_worker.cpp @@ -244,6 +244,8 @@ static worker::BuildResult handle_completion(const worker::BuildParams& params) cp.completion = {params.file, params.offset}; auto items = feature::code_complete(cp); + if(items.empty()) + LOG_DEBUG("Completion: no items returned for {}:{}", params.file, params.offset); LOG_DEBUG("Completion done: {} items, {}ms", items.size(), timer.ms()); worker::BuildResult result; @@ -267,7 +269,7 @@ static worker::BuildResult handle_signature_help(const worker::BuildParams& para cp.completion = {params.file, params.offset}; auto help = feature::signature_help(cp); - LOG_DEBUG("SignatureHelp done: {}ms", timer.ms()); + LOG_DEBUG("SignatureHelp done: {} signatures, {}ms", help.signatures.size(), timer.ms()); worker::BuildResult result; result.result_json = to_raw(help); diff --git a/tests/conftest.py b/tests/conftest.py index ada56698a..3a7ad3a9d 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -10,6 +10,14 @@ from tests.integration.utils.client import CliceClient +@pytest.hookimpl(tryfirst=True, hookwrapper=True) +def pytest_runtest_makereport(item, call): + """Store test outcome so fixtures can detect failures.""" + outcome = yield + rep = outcome.get_result() + setattr(item, f"rep_{rep.when}", rep) + + def pytest_addoption(parser: pytest.Parser) -> None: parser.addoption( "--executable", @@ -75,7 +83,8 @@ def workspace(request: pytest.FixtureRequest, test_data_dir: Path) -> Path | Non """ marker = request.node.get_closest_marker("workspace") if marker is None: - return None + yield None + return if not marker.args or not isinstance(marker.args[0], str): raise pytest.UsageError( "@pytest.mark.workspace requires a string argument, e.g. " @@ -88,7 +97,10 @@ def workspace(request: pytest.FixtureRequest, test_data_dir: Path) -> Path | Non clice_dir = path / ".clice" if clice_dir.exists(): shutil.rmtree(clice_dir) - return path + yield path + # Post-test cleanup: remove cache generated during the test. + if clice_dir.exists(): + shutil.rmtree(clice_dir) @pytest.fixture @@ -119,7 +131,11 @@ async def client( yield c - await _shutdown_client(c) + test_failed = ( + getattr(request.node, "rep_call", None) is not None + and request.node.rep_call.failed + ) + await _shutdown_client(c, verbose=test_failed) def generate_cdb(workspace: Path) -> None: @@ -152,8 +168,12 @@ async def make_client(executable: Path, workspace: Path) -> CliceClient: return c -async def _shutdown_client(c: CliceClient) -> None: - """Gracefully shut down a client, force-kill if needed.""" +async def _shutdown_client(c: CliceClient, *, verbose: bool = False) -> None: + """Gracefully shut down a client, force-kill if needed. + + When verbose=True (typically on test failure), dump collected log messages + and server stderr to help diagnose the failure. + """ try: await asyncio.wait_for(c.shutdown_async(None), timeout=3.0) except Exception: @@ -183,6 +203,11 @@ async def _shutdown_client(c: CliceClient) -> None: except Exception: pass + if verbose and c.log_messages: + for msg in c.log_messages: + level = {1: "ERROR", 2: "WARN", 3: "INFO", 4: "LOG"}.get(msg.type, "?") + print(f"[logMessage/{level}] {msg.message}", flush=True) + try: c._stop_event.set() for task in c._async_tasks: diff --git a/tests/integration/compilation/test_persistent_cache.py b/tests/integration/compilation/test_persistent_cache.py index fb7be2f7d..a7b3b6a64 100644 --- a/tests/integration/compilation/test_persistent_cache.py +++ b/tests/integration/compilation/test_persistent_cache.py @@ -16,6 +16,7 @@ from tests.conftest import make_client, shutdown_client from tests.integration.utils import write_cdb, doc +from tests.integration.utils.wait import MTIME_GRANULARITY, SETTLE_TIME from tests.integration.utils.cache import ( list_pch_files, list_pcm_files, @@ -100,7 +101,7 @@ async def test_pch_reused_on_close_reopen(client, tmp_path): # Close. client.text_document_did_close(DidCloseTextDocumentParams(text_document=doc(uri))) - await asyncio.sleep(0.5) + await asyncio.sleep(SETTLE_TIME) # Clear diagnostics so we can wait for fresh ones. client.diagnostics.pop(uri, None) @@ -227,7 +228,7 @@ async def test_pch_rebuilt_on_header_change(client, tmp_path): assert len(pch_before) >= 1 # Modify header — changes preamble content hash. - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "header.h").write_text("#pragma once\nstruct V2 { int b; };\n") # Also update main.cpp to use V2 so it compiles cleanly. (tmp_path / "main.cpp").write_text( @@ -236,7 +237,7 @@ async def test_pch_rebuilt_on_header_change(client, tmp_path): # Close and reopen to get fresh preamble. client.text_document_did_close(DidCloseTextDocumentParams(text_document=doc(uri))) - await asyncio.sleep(0.5) + await asyncio.sleep(SETTLE_TIME) client.diagnostics.pop(uri, None) uri2, _ = await client.open_and_wait(tmp_path / "main.cpp") diff --git a/tests/integration/compilation/test_staleness.py b/tests/integration/compilation/test_staleness.py index 88df093b3..10d738ea3 100644 --- a/tests/integration/compilation/test_staleness.py +++ b/tests/integration/compilation/test_staleness.py @@ -21,7 +21,7 @@ ) from tests.integration.utils import write_cdb, doc -from tests.integration.utils.wait import wait_for_recompile +from tests.integration.utils.wait import MTIME_GRANULARITY, wait_for_recompile from tests.integration.utils.assertions import assert_clean_compile, assert_has_errors @@ -42,7 +42,7 @@ async def test_header_change_invalidates_ast(client, tmp_path): # Modify header on disk — introduce an error. # Ensure mtime advances past filesystem granularity (1s on some FSes). - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "header.h").write_text( "inline int value() { return }\n" ) # syntax error @@ -71,7 +71,7 @@ async def test_header_change_invalidates_pch(client, tmp_path): # Modify header — rename struct field. # Ensure mtime advances past filesystem granularity (1s on some FSes). - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "header.h").write_text( "#pragma once\nstruct Foo { int y; };\n" # x -> y ) @@ -115,16 +115,22 @@ async def test_touch_without_content_change_skips_recompile(client, tmp_path): assert_clean_compile(client, uri) # Touch the header — mtime changes but content stays the same. - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) original_content = (tmp_path / "header.h").read_text() (tmp_path / "header.h").write_text(original_content) # Hover triggers ensure_compiled which runs deps_changed. # Layer 2 hash confirms nothing actually changed → cached AST reused. - # Hover on "main" (line 1, col 4) which should be hoverable. - hover = await client.text_document_hover_async( - HoverParams(text_document=doc(uri), position=Position(line=1, character=4)) - ) + # The first hover may see ast_dirty=true (mtime changed, hash check in progress), + # so retry to let the hash check complete. + hover = None + for _ in range(3): + hover = await client.text_document_hover_async( + HoverParams(text_document=doc(uri), position=Position(line=1, character=4)) + ) + if hover is not None: + break + await asyncio.sleep(SETTLE_TIME) assert hover is not None # No new diagnostics should appear — the file is still clean. @@ -145,7 +151,7 @@ async def test_header_replaced_with_different_content(client, tmp_path): assert_clean_compile(client, uri) # Replace header — delete and recreate with a breaking change. - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "header.h").unlink() (tmp_path / "header.h").write_text("inline int renamed_value() { return 1; }\n") @@ -170,7 +176,7 @@ async def test_fix_error_clears_diagnostics(client, tmp_path): assert_has_errors(client, uri, "Expected diagnostics from broken header") # Fix the header. - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "header.h").write_text("inline int value() { return 1; }\n") # Hover triggers recompilation — diagnostics should clear. @@ -198,7 +204,7 @@ async def test_multiple_files_share_header(client, tmp_path): assert_clean_compile(client, uri_b) # Break the shared header. - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "shared.h").write_text("inline int shared() { return }\n") # Both files should get diagnostics after hover. @@ -223,7 +229,7 @@ async def test_transitive_header_change(client, tmp_path): assert_clean_compile(client, uri) # Modify the transitive dep (base.h). - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "base.h").write_text("inline int base() { return }\n") # broken await wait_for_recompile(client, uri) @@ -310,7 +316,7 @@ async def test_didclose_then_reopen(client, tmp_path): client.text_document_did_close(DidCloseTextDocumentParams(text_document=doc(uri))) # Modify on disk while closed. - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "main.cpp").write_text("int main() { return }\n") # broken # Reopen — should compile the new (broken) content from disk. @@ -321,7 +327,7 @@ async def test_didclose_then_reopen(client, tmp_path): async def test_didclose_clears_hover(client, tmp_path): - """After didClose, hover on the closed file should return None.""" + """After didClose, hover on the closed file should return an error.""" (tmp_path / "main.cpp").write_text("int main() { return 0; }\n") write_cdb(tmp_path, ["main.cpp"]) await client.initialize(tmp_path) @@ -330,10 +336,10 @@ async def test_didclose_clears_hover(client, tmp_path): client.text_document_did_close(DidCloseTextDocumentParams(text_document=doc(uri))) - hover = await client.text_document_hover_async( - HoverParams(text_document=doc(uri), position=Position(line=0, character=4)) - ) - assert hover is None, "Hover on closed file should return None" + with pytest.raises(Exception, match="Document not open"): + await client.text_document_hover_async( + HoverParams(text_document=doc(uri), position=Position(line=0, character=4)) + ) async def test_didsave_triggers_recompile_for_dependents(client, tmp_path): @@ -349,7 +355,7 @@ async def test_didsave_triggers_recompile_for_dependents(client, tmp_path): assert_clean_compile(client, uri) # Modify header on disk and send didSave. - await asyncio.sleep(1.1) + await asyncio.sleep(MTIME_GRANULARITY) (tmp_path / "header.h").write_text("inline int value() { return }\n") # broken client.text_document_did_save( DidSaveTextDocumentParams( diff --git a/tests/integration/features/test_server.py b/tests/integration/features/test_server.py index 8b665710e..1db3c46ff 100644 --- a/tests/integration/features/test_server.py +++ b/tests/integration/features/test_server.py @@ -10,6 +10,7 @@ ) from tests.integration.utils import doc +from tests.integration.utils.wait import SETTLE_TIME from tests.integration.utils.workspace import did_change @@ -70,7 +71,7 @@ async def test_semantic_token_modifier_legend(client, workspace): @pytest.mark.workspace("hello_world") async def test_did_open_close_cycle(client, workspace): uri, _ = client.open(workspace / "main.cpp") - await asyncio.sleep(0.5) + await asyncio.sleep(SETTLE_TIME) client.close(uri) @@ -83,8 +84,8 @@ async def test_shutdown_exit(client, workspace): async def test_feature_requests_after_close(client, workspace): uri, _ = client.open(workspace / "main.cpp") client.close(uri) - result = await client.hover_at(uri, 0, 0) - assert result is None + with pytest.raises(Exception, match="Document not open"): + await client.hover_at(uri, 0, 0) @pytest.mark.workspace("hello_world") @@ -94,7 +95,7 @@ async def test_incremental_change(client, workspace): content += f"\n// change {i}" did_change(client, uri, i + 1, content) await asyncio.sleep(0.05) - await asyncio.sleep(1) + await asyncio.sleep(SETTLE_TIME * 2) client.close(uri) @@ -191,23 +192,23 @@ async def test_rapid_changes_stress(client, workspace): for i in range(20): content += f"\n// stress change {i}\n" did_change(client, uri, i + 1, content) - await asyncio.sleep(2) + await asyncio.sleep(SETTLE_TIME * 2) client.close(uri) @pytest.mark.workspace("hello_world") async def test_save_notification(client, workspace): uri, _ = client.open(workspace / "main.cpp") - await asyncio.sleep(0.5) + await asyncio.sleep(SETTLE_TIME) client.text_document_did_save(DidSaveTextDocumentParams(text_document=doc(uri))) - await asyncio.sleep(0.5) + await asyncio.sleep(SETTLE_TIME) client.close(uri) @pytest.mark.workspace("hello_world") async def test_hover_on_unknown_file(client, workspace): - result = await client.hover_at("file:///nonexistent/fake.cpp", 0, 0) - assert result is None + with pytest.raises(Exception, match="Document not open"): + await client.hover_at("file:///nonexistent/fake.cpp", 0, 0) @pytest.mark.workspace("hello_world") diff --git a/tests/integration/lifecycle/test_file_operation.py b/tests/integration/lifecycle/test_file_operation.py index f324ac733..c74406ff5 100644 --- a/tests/integration/lifecycle/test_file_operation.py +++ b/tests/integration/lifecycle/test_file_operation.py @@ -13,13 +13,14 @@ ) from tests.integration.utils import doc +from tests.integration.utils.wait import IDLE_TIMEOUT from tests.integration.utils.workspace import did_change @pytest.mark.workspace("hello_world") async def test_did_open(client, workspace): client.open(workspace / "main.cpp") - await asyncio.sleep(5) + await asyncio.sleep(IDLE_TIMEOUT) @pytest.mark.workspace("hello_world") @@ -29,13 +30,13 @@ async def test_did_change(client, workspace): content += "\n" await asyncio.sleep(0.2) did_change(client, uri, i + 1, content) - await asyncio.sleep(5) + await asyncio.sleep(IDLE_TIMEOUT) @pytest.mark.workspace("clang_tidy") async def test_clang_tidy(client, workspace): client.open(workspace / "main.cpp") - await asyncio.sleep(5) + await asyncio.sleep(IDLE_TIMEOUT) @pytest.mark.workspace("hello_world") @@ -56,7 +57,7 @@ async def test_hover_save_close(client, workspace): ) ) client.text_document_did_close(DidCloseTextDocumentParams(text_document=doc(uri))) - closed_hover = await client.text_document_hover_async( - HoverParams(text_document=doc(uri), position=Position(line=0, character=0)) - ) - assert closed_hover is None + with pytest.raises(Exception, match="Document not open"): + await client.text_document_hover_async( + HoverParams(text_document=doc(uri), position=Position(line=0, character=0)) + ) diff --git a/tests/integration/modules/test_modules.py b/tests/integration/modules/test_modules.py index b5690c512..edb37d9be 100644 --- a/tests/integration/modules/test_modules.py +++ b/tests/integration/modules/test_modules.py @@ -14,6 +14,7 @@ ) from tests.integration.utils.assertions import assert_clean_compile, assert_has_errors +from tests.integration.utils.wait import IDLE_TIMEOUT @pytest.mark.workspace("modules/single_module_no_deps") @@ -267,7 +268,7 @@ async def test_circular_module_dependency(client, workspace): the server remains responsive by opening a non-cyclic file afterwards. """ client.open(workspace / "cycle_a.cppm") - await asyncio.sleep(5.0) + await asyncio.sleep(IDLE_TIMEOUT) uri_ok, _ = await client.open_and_wait(workspace / "ok.cppm") diags = client.diagnostics.get(uri_ok, []) diff --git a/tests/integration/stress/test_rapid_edit.py b/tests/integration/stress/test_rapid_edit.py index 70ac47625..7c32a08f4 100644 --- a/tests/integration/stress/test_rapid_edit.py +++ b/tests/integration/stress/test_rapid_edit.py @@ -10,6 +10,7 @@ ) from tests.integration.utils import doc +from tests.integration.utils.wait import SETTLE_TIME from tests.integration.utils.workspace import did_change @@ -53,7 +54,7 @@ async def test_rapid_edits_with_hover(client, workspace): await asyncio.sleep(0.02) # ~20ms between edits # Wait a moment for in-flight requests to settle. - await asyncio.sleep(1.0) + await asyncio.sleep(SETTLE_TIME * 2) # Final hover must succeed and return correct result. final_hover = await asyncio.wait_for( diff --git a/tests/integration/utils/assertions.py b/tests/integration/utils/assertions.py index a2ed7b3c2..5420977ed 100644 --- a/tests/integration/utils/assertions.py +++ b/tests/integration/utils/assertions.py @@ -1,6 +1,6 @@ -"""Diagnostic assertion helpers for integration tests.""" +"""Diagnostic and log message assertion helpers for integration tests.""" -from lsprotocol.types import Diagnostic, DiagnosticSeverity +from lsprotocol.types import Diagnostic, DiagnosticSeverity, MessageType def get_errors(diagnostics: list[Diagnostic]) -> list[Diagnostic]: @@ -48,3 +48,23 @@ def assert_clean_compile(client, uri: str) -> None: """Assert the file compiled without any diagnostics at all.""" diags = client.diagnostics.get(uri, []) assert len(diags) == 0, f"Expected clean compile, got: {diags}" + + +def has_log_message( + client, substring: str, *, severity: MessageType | None = None +) -> bool: + """Check if any log message contains the given substring.""" + for msg in client.log_messages: + if severity is not None and msg.type != severity: + continue + if substring in msg.message: + return True + return False + + +def assert_no_log_errors(client) -> None: + """Assert that no error-level log messages were received.""" + errors = [m for m in client.log_messages if m.type == MessageType.Error] + assert len(errors) == 0, ( + f"Expected no log errors, got: {[e.message for e in errors]}" + ) diff --git a/tests/integration/utils/client.py b/tests/integration/utils/client.py index 7b4319c04..e26a3e41c 100644 --- a/tests/integration/utils/client.py +++ b/tests/integration/utils/client.py @@ -7,6 +7,7 @@ from lsprotocol.types import ( PROGRESS, TEXT_DOCUMENT_PUBLISH_DIAGNOSTICS, + WINDOW_LOG_MESSAGE, WINDOW_WORK_DONE_PROGRESS_CREATE, ClientCapabilities, CodeActionContext, @@ -24,6 +25,7 @@ InitializeParams, InitializeResult, InitializedParams, + LogMessageParams, Position, ProgressParams, PublishDiagnosticsParams, @@ -48,6 +50,7 @@ def __init__(self) -> None: super().__init__("clice-test-client", "0.1.0") self.diagnostics: dict[str, list[Diagnostic]] = {} self.diagnostics_events: dict[str, asyncio.Event] = {} + self.log_messages: list[LogMessageParams] = [] self.progress_tokens: list[str] = [] self.progress_events: list[dict] = [] self.init_result: InitializeResult | None = None @@ -64,6 +67,10 @@ def on_diagnostics(params: PublishDiagnosticsParams) -> None: if key in self.diagnostics_events: self.diagnostics_events[key].set() + @self.feature(WINDOW_LOG_MESSAGE) + def on_log_message(params: LogMessageParams) -> None: + self.log_messages.append(params) + @self.feature(WINDOW_WORK_DONE_PROGRESS_CREATE) def on_create_progress(params: WorkDoneProgressCreateParams) -> None: token = str(params.token) if isinstance(params.token, int) else params.token diff --git a/tests/integration/utils/wait.py b/tests/integration/utils/wait.py index 91d4a26ba..e0fe2d2b3 100644 --- a/tests/integration/utils/wait.py +++ b/tests/integration/utils/wait.py @@ -9,6 +9,11 @@ WorkspaceSymbolParams, ) +# Standard timing constants — use these instead of hardcoded sleep values. +MTIME_GRANULARITY = 1.1 # Filesystem mtime precision (1s on many FSes, +0.1 margin) +SETTLE_TIME = 0.5 # Time for server to stabilize after an operation +IDLE_TIMEOUT = 5.0 # Time to wait for server idle in lifecycle tests + async def wait_for_recompile(client, uri: str, *, timeout: float = 60.0) -> None: """Trigger recompilation via hover and wait for fresh diagnostics. diff --git a/tests/unit/feature/document_link_tests.cpp b/tests/unit/feature/document_link_tests.cpp index 4674fecdb..ff33d370a 100644 --- a/tests/unit/feature/document_link_tests.cpp +++ b/tests/unit/feature/document_link_tests.cpp @@ -21,11 +21,6 @@ void run(llvm::StringRef source, llvm::StringRef standard = "-std=c++17") { links = feature::document_links(*unit, feature::PositionEncoding::UTF8); } -auto to_local_range(const protocol::Range& range) -> LocalSourceRange { - feature::PositionMapper converter(unit->interested_content(), feature::PositionEncoding::UTF8); - return LocalSourceRange(*converter.to_offset(range.start), *converter.to_offset(range.end)); -} - void EXPECT_LINK(std::size_t index, llvm::StringRef name, llvm::StringRef path) { auto& link = links[index]; auto expected = range(name, "main.cpp"); diff --git a/tests/unit/feature/folding_range_tests.cpp b/tests/unit/feature/folding_range_tests.cpp index aec7c4509..3acfc6117 100644 --- a/tests/unit/feature/folding_range_tests.cpp +++ b/tests/unit/feature/folding_range_tests.cpp @@ -37,19 +37,10 @@ void run(llvm::StringRef code) { } auto to_local_range(const protocol::FoldingRange& range) -> LocalSourceRange { - feature::PositionMapper converter(unit->interested_content(), feature::PositionEncoding::UTF8); - - auto start = protocol::Position{ - .line = range.start_line, - .character = range.start_character.value_or(0), - }; - - auto end = protocol::Position{ - .line = range.end_line, - .character = range.end_character.value_or(0), - }; - - return LocalSourceRange(*converter.to_offset(start), *converter.to_offset(end)); + return Tester::to_local_range(protocol::Range{ + .start = {.line = range.start_line, .character = range.start_character.value_or(0)}, + .end = {.line = range.end_line, .character = range.end_character.value_or(0) }, + }); } void EXPECT_FOLDING(std::uint32_t index, diff --git a/tests/unit/test/tester.h b/tests/unit/test/tester.h index c372b19ec..e3796b0fd 100644 --- a/tests/unit/test/tester.h +++ b/tests/unit/test/tester.h @@ -8,6 +8,7 @@ #include "test/test.h" #include "command/command.h" #include "compile/compilation.h" +#include "feature/feature.h" #include "support/logging.h" namespace clice::testing { @@ -82,6 +83,12 @@ struct Tester { LocalSourceRange range(llvm::StringRef name = "", llvm::StringRef file = ""); + LocalSourceRange to_local_range(const kota::ipc::protocol::Range& range) { + feature::PositionMapper converter(unit->interested_content(), + feature::PositionEncoding::UTF8); + return LocalSourceRange(*converter.to_offset(range.start), *converter.to_offset(range.end)); + } + void clear(); };