From da30750ba48b6cd610ed0234e091448ed6312f4a Mon Sep 17 00:00:00 2001 From: Steven Troxler Date: Mon, 13 Feb 2023 15:17:29 -0800 Subject: [PATCH] Use DaemonStatus to encapsulate time + connection status Summary: We always want both the connection status before and information about how long it has been since the server is ready; this combination of information makes it much easier to judge how big a problem availability is, because - we can't decide whether incremental status is bad or not *at all* without a timer, since it's expected that we'll be briefly busy - even for other statuses like starting, it's very helpful to have a record of how long start took; this, for example, can help us distinguish between an availability problem due primarily to long start times versus a problem due primarilily to frequent deamon (or persistent) restarts Putting these fields in the same dataclass makes it easier to ensure we always do the right thing, and that the logging is consistent across all telemetry events. It's worth noting that I caught another bug here: we weren't logging status in the telemetry for type coverage; this isn't a big deal today but it could be one if we ever start seeing heavy use of expression-level coverage. Reviewed By: grievejia Differential Revision: D43244195 fbshipit-source-id: d5ff1b0a39e2b09e3873a3131373a7f466c77d5d --- client/commands/pyre_language_server.py | 47 ++++++++----------------- client/commands/server_state.py | 35 ++++++++++++------ 2 files changed, 39 insertions(+), 43 deletions(-) diff --git a/client/commands/pyre_language_server.py b/client/commands/pyre_language_server.py index 178b0cca80f..1dd266081c8 100644 --- a/client/commands/pyre_language_server.py +++ b/client/commands/pyre_language_server.py @@ -289,11 +289,9 @@ async def process_did_change_request( if document_path not in self.server_state.opened_documents: return - time_since_last_ready_ms = ( - self.server_state.status_tracker.milliseconds_not_ready() - ) - server_status_before = self.server_state.status_tracker.get_status().value + daemon_status_before = self.server_state.status_tracker.get_status() did_change_timer = timer.Timer() + process_unsaved_changes = ( self.server_state.server_options.language_server_features.unsaved_changes.is_enabled() ) @@ -324,10 +322,9 @@ async def process_did_change_request( self.server_state.opened_documents ), "duration_ms": did_change_timer.stop_in_millisecond(), - "time_since_last_ready_ms": time_since_last_ready_ms, - "server_status_before": str(server_status_before), "error_message": error_message, "overlays_enabled": process_unsaved_changes, + **daemon_status_before.as_telemetry_dict(), }, activity_key, ) @@ -347,10 +344,7 @@ async def process_did_save_request( if document_path not in self.server_state.opened_documents: return - time_since_last_ready_ms = ( - self.server_state.status_tracker.milliseconds_not_ready() - ) - server_status_before = self.server_state.status_tracker.get_status().value + daemon_status_before = self.server_state.status_tracker.get_status() code_changes = self.server_state.opened_documents[document_path].code @@ -371,11 +365,10 @@ async def process_did_save_request( "server_state_open_documents_count": len( self.server_state.opened_documents ), - "server_status_before": str(server_status_before), - "time_since_last_ready_ms": time_since_last_ready_ms, # We don't do any blocking work on didSave, but analytics are easier if # we avoid needlessly introducing NULL values. "duration_ms": 0, + **daemon_status_before.as_telemetry_dict(), }, activity_key, ) @@ -392,11 +385,10 @@ async def process_type_coverage_request( f"Document URI is not a file: {parameters.text_document.uri}" ) document_path = document_path.resolve() - time_since_last_ready_ms = ( - self.server_state.status_tracker.milliseconds_not_ready() - ) - server_status_before = self.server_state.status_tracker.get_status().value + + daemon_status_before = self.server_state.status_tracker.get_status() type_coverage_timer = timer.Timer() + response = await self.querier.get_type_coverage(path=document_path) if response is not None: await lsp.write_json_rpc( @@ -413,12 +405,8 @@ async def process_type_coverage_request( "operation": "typeCoverage", "filePath": str(document_path), "duration_ms": type_coverage_timer.stop_in_millisecond(), - "time_since_last_ready_ms": time_since_last_ready_ms, - "server_state_open_documents_count": len( - self.server_state.opened_documents - ), - "server_status_before": str(server_status_before), "coverage_type": self.get_language_server_features().type_coverage.value, + **daemon_status_before.as_telemetry_dict(), }, activity_key, ) @@ -451,11 +439,9 @@ async def process_hover_request( ), ) else: - time_since_last_ready_ms = ( - self.server_state.status_tracker.milliseconds_not_ready() - ) - server_status_before = self.server_state.status_tracker.get_status().value + daemon_status_before = self.server_state.status_tracker.get_status() hover_timer = timer.Timer() + await self.update_overlay_if_needed(document_path) result = await self.querier.get_hover( path=document_path, @@ -489,13 +475,12 @@ async def process_hover_request( "nonEmpty": len(result.contents) > 0, "response": raw_result, "duration_ms": hover_timer.stop_in_millisecond(), - "time_since_last_ready_ms": time_since_last_ready_ms, "server_state_open_documents_count": len( self.server_state.opened_documents ), - "server_status_before": str(server_status_before), "error_message": error_message, "overlays_enabled": self.server_state.server_options.language_server_features.unsaved_changes.is_enabled(), + **daemon_status_before.as_telemetry_dict(), }, activity_key, ) @@ -559,10 +544,7 @@ async def process_definition_request( result=lsp.LspLocation.cached_schema().dump([], many=True), ), ) - time_since_last_ready_ms = ( - self.server_state.status_tracker.milliseconds_not_ready() - ) - server_status_before = self.server_state.status_tracker.get_status().value + daemon_status_before = self.server_state.status_tracker.get_status() shadow_mode = self.get_language_server_features().definition.is_shadow() # In shadow mode, we need to return an empty response immediately if shadow_mode: @@ -608,17 +590,16 @@ async def process_definition_request( "count": len(output_result), "response": output_result, "duration_ms": result_with_durations.overall_duration, - "time_since_last_ready_ms": time_since_last_ready_ms, "overlay_update_duration": result_with_durations.overlay_update_duration, "query_duration": result_with_durations.query_duration, "server_state_open_documents_count": len( self.server_state.opened_documents ), - "server_status_before": str(server_status_before), "overlays_enabled": self.server_state.server_options.language_server_features.unsaved_changes.is_enabled(), "error_message": error_message, "is_dirty": self.server_state.opened_documents[document_path].is_dirty, "truncated_file_contents": source_code_if_sampled, + **daemon_status_before.as_telemetry_dict(), }, activity_key, ) diff --git a/client/commands/server_state.py b/client/commands/server_state.py index 77b48c47da5..91d7f0e1a93 100644 --- a/client/commands/server_state.py +++ b/client/commands/server_state.py @@ -9,6 +9,7 @@ should be aware a change to this state could affect other modules that interact with this state. """ +from __future__ import annotations import dataclasses import enum @@ -33,6 +34,18 @@ class ConnectionStatus(enum.Enum): STARTING = "STARTING" +@dataclasses.dataclass(frozen=True) +class DaemonStatus: + connection_status: ConnectionStatus + milliseconds_since_ready: float + + def as_telemetry_dict(self) -> Dict[str, float | str]: + return { + "server_state_before": self.connection_status.value, + "time_since_last_ready_ms": self.milliseconds_since_ready, + } + + @dataclasses.dataclass(frozen=True) class OpenedDocumentState: code: str @@ -42,7 +55,7 @@ class OpenedDocumentState: @dataclasses.dataclass class DaemonStatusTracker: - _status: ConnectionStatus = ConnectionStatus.NOT_CONNECTED + _connection_status: ConnectionStatus = ConnectionStatus.NOT_CONNECTED _not_ready_timer: Optional[timer.Timer] = None def set_status(self, new_status: ConnectionStatus) -> None: @@ -50,15 +63,17 @@ def set_status(self, new_status: ConnectionStatus) -> None: self._not_ready_timer = None elif self._not_ready_timer is None: self._not_ready_timer = timer.Timer() - self._status = new_status - - def get_status(self) -> ConnectionStatus: - return self._status - - def milliseconds_not_ready(self) -> int: - if self._not_ready_timer is None: - return 0 - return int(self._not_ready_timer.stop_in_millisecond()) + self._connection_status = new_status + + def get_status(self) -> DaemonStatus: + return DaemonStatus( + connection_status=self._connection_status, + milliseconds_since_ready=( + 0 + if self._not_ready_timer is None + else self._not_ready_timer.stop_in_millisecond() + ), + ) @dataclasses.dataclass