foster/denoland-deno
0
0
Fork 0
mirror of https://github.com/denoland/deno.git synced 2024-10-29 08:58:01 -04:00
Code Issues Wiki Activity

refactor(lsp): log names (#21413)

Browse source 
This commit changes LSP log names by prefixing them, we now have these
prefixes:
- `lsp.*` - requests coming from the client
- `tsc.request.*` - requests coming from clients that are routed to TSC
- `tsc.op.*` - ops called by the TS host
- `tsc.host.*` - requests that call JavaScript runtime that runs
TypeScript compiler host

Additionall `Performance::mark` was split into `Performance::mark` and
`Performance::mark_with_args` to reduce verbosity of code and logs.
This commit is contained in:
Bartek Iwańczuk 2023-12-01 03:54:59 +01:00
parent 8c07f52a7c
commit 950b712dda
No known key found for this signature in database
GPG key ID: 0C6BCDDC3B3AD750
6 changed files with 124 additions and 80 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

9
cli/lsp/diagnostics.rs
View file

@ -493,8 +493,7 @@ impl DiagnosticsServer {
_ = tokio::time::sleep(DELAY) => {}
};
let mark =
performance.mark("update_diagnostics_ts", None::<()>);
let mark = performance.mark("lsp.update_diagnostics_ts");
let diagnostics = generate_ts_diagnostics(
snapshot.clone(),
&config,
@ -549,8 +548,7 @@ impl DiagnosticsServer {
if let Some(previous_handle) = previous_deps_handle {
previous_handle.await;
}
let mark =
performance.mark("update_diagnostics_deps", None::<()>);
let mark = performance.mark("lsp.update_diagnostics_deps");
let diagnostics = spawn_blocking({
let token = token.clone();
move || generate_deno_diagnostics(&snapshot, &config, token)
@ -599,8 +597,7 @@ impl DiagnosticsServer {
if let Some(previous_handle) = previous_lint_handle {
previous_handle.await;
}
let mark =
performance.mark("update_diagnostics_lint", None::<()>);
let mark = performance.mark("lsp.update_diagnostics_lint");
let diagnostics = spawn_blocking({
let token = token.clone();
move || {

110
cli/lsp/language_server.rs
View file

@ -546,9 +546,9 @@ impl Inner {
&self,
specifier: &ModuleSpecifier,
) -> Result<Arc<tsc::NavigationTree>, AnyError> {
let mark = self.performance.mark(
"get_navigation_tree",
Some(json!({ "specifier": specifier })),
let mark = self.performance.mark_with_args(
"lsp.get_navigation_tree",
json!({ "specifier": specifier }),
);
let asset_or_doc = self.get_asset_or_document(specifier)?;
let navigation_tree =
@ -715,7 +715,7 @@ impl Inner {
}
pub async fn update_cache(&mut self) -> Result<(), AnyError> {
let mark = self.performance.mark("update_cache", None::<()>);
let mark = self.performance.mark("lsp.update_cache");
self.performance.measure(mark);
let maybe_cache = &self.config.workspace_settings().cache;
let maybe_global_cache_path = if let Some(cache_str) = maybe_cache {
@ -844,7 +844,7 @@ impl Inner {
}
pub async fn update_import_map(&mut self) -> Result<(), AnyError> {
let mark = self.performance.mark("update_import_map", None::<()>);
let mark = self.performance.mark("lsp.update_import_map");
let maybe_import_map_url = self.resolve_import_map_specifier()?;
if let Some(import_map_url) = maybe_import_map_url {
@ -979,7 +979,7 @@ impl Inner {
}
async fn update_registries(&mut self) -> Result<(), AnyError> {
let mark = self.performance.mark("update_registries", None::<()>);
let mark = self.performance.mark("lsp.update_registries");
self.recreate_http_client_and_dependents().await?;
let workspace_settings = self.config.workspace_settings();
for (registry, enabled) in workspace_settings.suggest.imports.hosts.iter() {
@ -1035,7 +1035,7 @@ impl Inner {
}
async fn update_tsconfig(&mut self) -> Result<(), AnyError> {
let mark = self.performance.mark("update_tsconfig", None::<()>);
let mark = self.performance.mark("lsp.update_tsconfig");
let mut tsconfig = TsConfig::new(json!({
"allowJs": true,
"esModuleInterop": true,
@ -1129,7 +1129,7 @@ impl Inner {
params: InitializeParams,
) -> LspResult<InitializeResult> {
lsp_log!("Starting Deno language server...");
let mark = self.performance.mark("initialize", Some(&params));
let mark = self.performance.mark_with_args("lsp.initialize", &params);
// exit this process when the parent is lost
if let Some(parent_pid) = params.process_id {
@ -1295,7 +1295,7 @@ impl Inner {
specifier: &ModuleSpecifier,
params: DidOpenTextDocumentParams,
) -> Document {
let mark = self.performance.mark("did_open", Some(&params));
let mark = self.performance.mark_with_args("lsp.did_open", &params);
let language_id =
params
.text_document
@ -1324,7 +1324,7 @@ impl Inner {
}
async fn did_change(&mut self, params: DidChangeTextDocumentParams) {
let mark = self.performance.mark("did_change", Some(&params));
let mark = self.performance.mark_with_args("lsp.did_change", &params);
let specifier = self
.url_map
.normalize_url(&params.text_document.uri, LspUrlKind::File);
@ -1367,7 +1367,7 @@ impl Inner {
}
async fn did_close(&mut self, params: DidCloseTextDocumentParams) {
let mark = self.performance.mark("did_close", Some(&params));
let mark = self.performance.mark_with_args("lsp.did_close", &params);
self.diagnostics_state.clear(&params.text_document.uri);
if params.text_document.uri.scheme() == "deno" {
// we can ignore virtual text documents closing, as they don't need to
@ -1506,7 +1506,7 @@ impl Inner {
let mark = self
.performance
.mark("did_change_watched_files", Some(&params));
.mark_with_args("lsp.did_change_watched_files", &params);
let mut touched = false;
let changes: IndexSet<Url> = params
.changes
@ -1660,7 +1660,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("document_symbol", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.document_symbol", &params);
let asset_or_document = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_document.line_index();
@ -1714,7 +1716,7 @@ impl Inner {
error!("{}", err);
LspError::invalid_request()
})?;
let mark = self.performance.mark("formatting", Some(&params));
let mark = self.performance.mark_with_args("lsp.formatting", &params);
// spawn a blocking task to allow doing other work while this is occurring
let text_edits = deno_core::unsync::spawn_blocking({
@ -1780,7 +1782,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("hover", Some(&params));
let mark = self.performance.mark_with_args("lsp.hover", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let hover = if let Some((_, dep, range)) = asset_or_doc
.get_maybe_dependency(&params.text_document_position_params.position)
@ -1861,7 +1863,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("code_action", Some(&params));
let mark = self.performance.mark_with_args("lsp.code_action", &params);
let mut all_actions = CodeActionResponse::new();
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2044,7 +2046,9 @@ impl Inner {
return Ok(params);
}
let mark = self.performance.mark("code_action_resolve", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.code_action_resolve", &params);
let kind = params.kind.clone().unwrap();
let data = params.data.clone().unwrap();
@ -2151,7 +2155,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("code_lens", Some(&params));
let mark = self.performance.mark_with_args("lsp.code_lens", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let settings = self.config.workspace_settings_for_specifier(&specifier);
let mut code_lenses = Vec::new();
@ -2208,7 +2212,9 @@ impl Inner {
&self,
code_lens: CodeLens,
) -> LspResult<CodeLens> {
let mark = self.performance.mark("code_lens_resolve", Some(&code_lens));
let mark = self
.performance
.mark_with_args("lsp.code_lens_resolve", &code_lens);
let result = if code_lens.data.is_some() {
code_lens::resolve_code_lens(code_lens, self)
.await
@ -2239,7 +2245,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("document_highlight", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.document_highlight", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
let files_to_search = vec![specifier.clone()];
@ -2280,7 +2288,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("references", Some(&params));
let mark = self.performance.mark_with_args("lsp.references", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
let maybe_referenced_symbols = self
@ -2336,7 +2344,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("goto_definition", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.goto_definition", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
let maybe_definition = self
@ -2372,7 +2382,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("goto_definition", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.goto_definition", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
let maybe_definition_info = self
@ -2418,7 +2430,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("completion", Some(&params));
let mark = self.performance.mark_with_args("lsp.completion", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
// Import specifiers are something wholly internal to Deno, so for
// completions, we will use internal logic and if there are completions
@ -2498,7 +2510,9 @@ impl Inner {
&self,
params: CompletionItem,
) -> LspResult<CompletionItem> {
let mark = self.performance.mark("completion_resolve", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.completion_resolve", &params);
let completion_item = if let Some(data) = &params.data {
let data: completions::CompletionItemData =
serde_json::from_value(data.clone()).map_err(|err| {
@ -2580,7 +2594,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("goto_implementation", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.goto_implementation", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2622,7 +2638,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("folding_range", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.folding_range", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let outlining_spans = self
@ -2663,7 +2681,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("incoming_calls", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.incoming_calls", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2706,7 +2726,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("outgoing_calls", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.outgoing_calls", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2753,7 +2775,7 @@ impl Inner {
let mark = self
.performance
.mark("prepare_call_hierarchy", Some(&params));
.mark_with_args("lsp.prepare_call_hierarchy", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2814,7 +2836,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("rename", Some(&params));
let mark = self.performance.mark_with_args("lsp.rename", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2857,7 +2879,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("selection_range", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.selection_range", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2890,7 +2914,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("semantic_tokens_full", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.semantic_tokens_full", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2927,7 +2953,7 @@ impl Inner {
let mark = self
.performance
.mark("semantic_tokens_range", Some(&params));
.mark_with_args("lsp.semantic_tokens_range", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
@ -2966,7 +2992,9 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("signature_help", Some(&params));
let mark = self
.performance
.mark_with_args("lsp.signature_help", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
let options = if let Some(context) = params.context {
@ -3047,7 +3075,7 @@ impl Inner {
&self,
params: WorkspaceSymbolParams,
) -> LspResult<Option<Vec<SymbolInformation>>> {
let mark = self.performance.mark("symbol", Some(&params));
let mark = self.performance.mark_with_args("lsp.symbol", &params);
let navigate_to_items = self
.ts_server
@ -3322,7 +3350,7 @@ impl tower_lsp::LanguageServer for LanguageServer {
let inner = self.0.read().await;
inner
.performance
.mark("did_change_configuration", Some(&params))
.mark_with_args("lsp.did_change_configuration", &params)
};
self.refresh_configuration().await;
@ -3347,7 +3375,7 @@ impl tower_lsp::LanguageServer for LanguageServer {
let mut ls = self.0.write().await;
let mark = ls
.performance
.mark("did_change_workspace_folders", Some(&params));
.mark_with_args("lsp.did_change_workspace_folders", &params);
ls.did_change_workspace_folders(params);
(ls.performance.clone(), mark)
};
@ -3559,7 +3587,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("cache", Some(&params));
let mark = self.performance.mark_with_args("lsp.cache", &params);
let roots = if !params.uris.is_empty() {
params
.uris
@ -3665,7 +3693,7 @@ impl Inner {
return Ok(None);
}
let mark = self.performance.mark("inlay_hint", Some(&params));
let mark = self.performance.mark_with_args("lsp.inlay_hint", &params);
let asset_or_doc = self.get_asset_or_document(&specifier)?;
let line_index = asset_or_doc.line_index();
let text_span =
@ -3718,7 +3746,7 @@ impl Inner {
) -> LspResult<Option<String>> {
let mark = self
.performance
.mark("virtual_text_document", Some(&params));
.mark_with_args("lsp.virtual_text_document", &params);
let specifier = self
.url_map
.normalize_url(&params.text_document.uri, LspUrlKind::File);

33
cli/lsp/performance.rs
View file

@ -132,10 +132,7 @@ impl Performance {
.collect()
}
/// Marks the start of a measurement which returns a performance mark
/// structure, which is then passed to `.measure()` to finalize the duration
/// and add it to the internal buffer.
pub fn mark<S: AsRef<str>, V: Serialize>(
fn mark_inner<S: AsRef<str>, V: Serialize>(
&self,
name: S,
maybe_args: Option<V>,
@ -165,6 +162,24 @@ impl Performance {
}
}
/// Marks the start of a measurement which returns a performance mark
/// structure, which is then passed to `.measure()` to finalize the duration
/// and add it to the internal buffer.
pub fn mark<S: AsRef<str>>(&self, name: S) -> PerformanceMark {
self.mark_inner(name, None::<()>)
}
/// Marks the start of a measurement which returns a performance mark
/// structure, which is then passed to `.measure()` to finalize the duration
/// and add it to the internal buffer.
pub fn mark_with_args<S: AsRef<str>, V: Serialize>(
&self,
name: S,
args: V,
) -> PerformanceMark {
self.mark_inner(name, Some(args))
}
/// A function which accepts a previously created performance mark which will
/// be used to finalize the duration of the span being measured, and add the
/// measurement to the internal buffer.
@ -201,9 +216,9 @@ mod tests {
#[test]
fn test_average() {
let performance = Performance::default();
let mark1 = performance.mark("a", None::<()>);
let mark2 = performance.mark("a", None::<()>);
let mark3 = performance.mark("b", None::<()>);
let mark1 = performance.mark("a");
let mark2 = performance.mark("a");
let mark3 = performance.mark("b");
performance.measure(mark2);
performance.measure(mark1);
performance.measure(mark3);
@ -217,8 +232,8 @@ mod tests {
#[test]
fn test_averages() {
let performance = Performance::default();
let mark1 = performance.mark("a", None::<()>);
let mark2 = performance.mark("a", None::<()>);
let mark1 = performance.mark("a");
let mark2 = performance.mark("a");
performance.measure(mark2);
performance.measure(mark1);
let averages = performance.averages();

2
cli/lsp/testing/server.rs
View file

@ -87,7 +87,7 @@ impl TestServer {
match update_rx.recv().await {
None => break,
Some(snapshot) => {
let mark = performance.mark("testing_update", None::<()>);
let mark = performance.mark("lsp.testing_update");
let mut tests = tests.lock();
// we create a list of test modules we currently are tracking
// eliminating any we go over when iterating over the document

12
cli/lsp/tsc.rs
View file

@ -954,9 +954,7 @@ impl TsServer {
where
R: de::DeserializeOwned,
{
let mark = self
.performance
.mark(format!("tsc {}", req.method), None::<()>);
let mark = self.performance.mark(format!("tsc.request.{}", req.method));
let r = self
.request_with_cancellation(snapshot, req, Default::default())
.await;
@ -3910,7 +3908,7 @@ fn op_resolve(
#[serde] args: ResolveArgs,
) -> Result<Vec<Option<(String, String)>>, AnyError> {
let state = state.borrow_mut::<State>();
let mark = state.performance.mark("op_resolve", Some(&args));
let mark = state.performance.mark_with_args("tsc.op.op_resolve", &args);
let referrer = state.specifier_map.normalize(&args.base)?;
let result = match state.get_asset_or_document(&referrer) {
Some(referrer_doc) => {
@ -4438,8 +4436,10 @@ fn request(
let id = state.last_id;
(state.performance.clone(), id)
};
let mark =
performance.mark("request", Some((request.method, request.args.clone())));
let mark = performance.mark_with_args(
format!("tsc.host.{}", request.method),
request.args.clone(),
);
assert!(
request.args.is_array(),
"Internal error: expected args to be array"

38
cli/tests/integration/lsp_tests.rs
View file

@ -8303,23 +8303,27 @@ fn lsp_performance() {
assert_eq!(
averages,
vec![
"did_open",
"hover",
"initialize",
"op_load",
"request",
"testing_update",
"tsc $configure",
"tsc $getAssets",
"tsc $getSupportedCodeFixes",
"tsc getQuickInfoAtPosition",
"update_cache",
"update_diagnostics_deps",
"update_diagnostics_lint",
"update_diagnostics_ts",
"update_import_map",
"update_registries",
"update_tsconfig",
"lsp.did_open",
"lsp.hover",
"lsp.initialize",
"lsp.testing_update",
"lsp.update_cache",
"lsp.update_diagnostics_deps",
"lsp.update_diagnostics_lint",
"lsp.update_diagnostics_ts",
"lsp.update_import_map",
"lsp.update_registries",
"lsp.update_tsconfig",
"tsc.host.$configure",
"tsc.host.$getAssets",
"tsc.host.$getDiagnostics",
"tsc.host.$getSupportedCodeFixes",
"tsc.host.getQuickInfoAtPosition",
"tsc.op.op_load",
"tsc.request.$configure",
"tsc.request.$getAssets",
"tsc.request.$getSupportedCodeFixes",
"tsc.request.getQuickInfoAtPosition",
]
);
client.shutdown();