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

@@ -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.
         """

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,