Skip to content

Commit

Permalink
Use DaemonStatus to encapsulate time + connection status
Browse files Browse the repository at this point in the history
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
  • Loading branch information
stroxler authored and facebook-github-bot committed Feb 13, 2023
1 parent 564e2bb commit da30750
Show file tree
Hide file tree
Showing 2 changed files with 39 additions and 43 deletions.
47 changes: 14 additions & 33 deletions client/commands/pyre_language_server.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()
)
Expand Down Expand Up @@ -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,
)
Expand All @@ -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

Expand All @@ -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,
)
Expand All @@ -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(
Expand All @@ -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,
)
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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,
)
Expand Down Expand Up @@ -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:
Expand Down Expand Up @@ -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,
)
Expand Down
35 changes: 25 additions & 10 deletions client/commands/server_state.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand All @@ -42,23 +55,25 @@ 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:
if new_status == ConnectionStatus.READY:
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
Expand Down

0 comments on commit da30750

Please sign in to comment.