From 12b1e9b7bc2782042968859e01bb59b16232da25 Mon Sep 17 00:00:00 2001
From: Athanasius <github@miggy.org>
Date: Sat, 28 Aug 2021 13:58:46 +0100
Subject: [PATCH] CAPI: Add more trace_if('capi.worker', ...) to check timings
I keep observing it take 3-4s to update the UI after a manual CAPI
request. This showed up as mostly *in*
AppWindow.capi_handle_response(), but the moment I ran it under PyCharm
profile that went down to 400ms.
---
EDMarketConnector.py | 5 +++++
companion.py | 7 ++++++-
2 files changed, 11 insertions(+), 1 deletion(-)
diff --git a/EDMarketConnector.py b/EDMarketConnector.py
index c2d3621d..425550ce 100755
--- a/EDMarketConnector.py
+++ b/EDMarketConnector.py
@@ -900,6 +900,7 @@ class AppWindow(object):
:param event: Tk generated event details.
"""
+ logger.trace_if('capi.worker', 'Begin')
auto_update = not event
play_sound = (auto_update or int(event.type) == self.EVENT_VIRTUAL) and not config.get_int('hotkey_mute')
@@ -937,6 +938,7 @@ class AppWindow(object):
query_time = int(time())
logger.trace_if('capi.worker', 'Requesting full station data')
config.set('querytime', query_time)
+ logger.trace_if('capi.worker', 'Calling companion.session.station')
companion.session.station(
query_time=query_time, tk_response_event=self._CAPI_RESPONSE_TK_EVENT_NAME,
play_sound=play_sound
@@ -944,6 +946,7 @@ class AppWindow(object):
def capi_handle_response(self, event=None): # noqa: C901, CCR001
"""Handle the resulting data from a CAPI query."""
+ logger.trace_if('capi.worker', 'Handling response')
play_bad: bool = False
err: Optional[str] = None
@@ -1151,9 +1154,11 @@ class AppWindow(object):
# Update Odyssey Suit data
companion.session.suit_update(capi_response.capi_data)
+ logger.trace_if('capi.worker', 'Updating suit and cooldown...')
self.update_suit_text()
self.suit_show_if_set()
self.cooldown()
+ logger.trace_if('capi.worker', '...done')
def journal_event(self, event): # noqa: C901, CCR001 # Currently not easily broken up.
"""
diff --git a/companion.py b/companion.py
index f69ae122..11ee0a5b 100644
--- a/companion.py
+++ b/companion.py
@@ -734,7 +734,7 @@ class Session(object):
"""Worker thread that performs actual CAPI queries."""
logger.debug('CAPI worker thread starting')
- def capi_single_query(capi_endpoint: str, timeout: int = capi_default_timeout) -> CAPIData:
+ def capi_single_query(capi_endpoint: str, timeout: int = capi_default_timeout) -> CAPIData: # noqa: CCR001
"""
Perform a *single* CAPI endpoint query within the thread worker.
@@ -744,7 +744,9 @@ class Session(object):
"""
capi_data: CAPIData
try:
+ logger.trace_if('capi.worker', 'Sending HTTP request...')
r = self.session.get(self.server + capi_endpoint, timeout=timeout) # type: ignore
+ logger.trace_if('capi.worker', '... got result...')
r.raise_for_status() # Typically 403 "Forbidden" on token expiry
# May also fail here if token expired since response is empty
capi_json = r.json()
@@ -871,6 +873,7 @@ class Session(object):
while True:
query = self.capi_request_queue.get()
+ logger.trace_if('capi.worker', 'De-queued request')
if not isinstance(query, EDMCCAPIRequest):
logger.error("Item from queue wasn't an EDMCCAPIRequest")
break
@@ -934,6 +937,7 @@ class Session(object):
# If the query came from EDMC.(py|exe) there's no tk to send an
# event too, so assume it will be polling there response queue.
if query.tk_response_event is not None:
+ logger.trace_if('capi.worker', 'Sending <<CAPIResponse>>')
self.tk_master.event_generate('<<CAPIResponse>>')
logger.info('CAPI worker thread DONE')
@@ -1024,6 +1028,7 @@ class Session(object):
:param auto_update: Whether this request was triggered automatically.
"""
# Ask the thread worker to perform all three queries
+ logger.trace_if('capi.worker', 'Enqueueing request')
self.capi_request_queue.put(
EDMCCAPIRequest(
endpoint=self._CAPI_PATH_STATION,