Merge pull request #1217 from EDCD/fix/1134/edsm-wrong-balance

Investigate & fix wrong-commander EDSM data

Contributing.md

@@ -225,7 +225,39 @@ Adding `--trace` to a `pytest` invocation causes it to drop into a
 [`pdb`](https://docs.python.org/3/library/pdb.html) prompt for each test,
 handy if you want to step through the testing code to be sure of anything.
 
-Otherwise, see the [pytest documentation](https://docs.pytest.org/en/stable/contents.html).
+Otherwise, see the [pytest documentation](https://docs.pytest.org/en/stable/contents.html). 
+
+---
+## Debugging network sends
+
+Rather than risk sending bad data to a remote service, even if only through
+repeatedly sending the same data you can cause such code to instead send 
+through a local web server and thence to a log file.
+
+1. This utilises the `--debug-sender ...` command-line argument.  The argument
+  to this is free-form, so there's nothing to edit in EDMarketConnector.py 
+  in order to support a new target for this.
+2. The debug web server is set up globally in EDMarketConnector.py.
+3. In code where you want to utilise this you will need at least something 
+  like this (taken from some plugins/edsm.py code):
+
+```python
+from config import debug_senders
+from edmc_data import DEBUG_WEBSERVER_HOST, DEBUG_WEBSERVER_PORT
+
+TARGET_URL = 'https://www.edsm.net/api-journal-v1'
+if 'edsm' in debug_senders:
+    TARGET_URL = f'http://{DEBUG_WEBSERVER_HOST}:{DEBUG_WEBSERVER_PORT}/edsm'
+
+...
+    r = this.session.post(TARGET_URL, data=data, timeout=_TIMEOUT)
+```
+
+   Be sure to set a URL path in the `TARGET_URL` that denotes where the data
+   would normally be sent to.
+4. The output will go into a file in `%TEMP%\EDMarketConnector\http_debug` 
+  whose name is based on the path component of the URL.  In the code example 
+  above it will come out as `edsm.log` due to how `TARGET_URL` is set.
 
 ---
 
@@ -376,6 +408,22 @@ In addition to that we utilise one of the user-defined levels as:
   command-line argument and `.bat` file for users to enable it.  It cannot be
   selected from Settings in the UI.
 
+  As well as just using bare `logger.trace(...)` you can also gate it to only
+  log if asked to at invocation time by utilising the `--trace-on ...` 
+  command-line argument.  e.g.
+ `EDMarketConnector.py --trace --trace-on edsm-cmdr-events`.  Note how you
+  still need to include `--trace`. The code to check and log would be like:
+
+    ```python
+    from config import trace_on
+
+    if 'edsm-cmdr-events' in trace_on:
+        logger.trace(f'De-queued ({cmdr=}, {entry["event"]=})')
+  ```
+  
+  This way you can set up TRACE logging that won't spam just because of 
+  `--trace` being used.
+
 ---
 
 ## Use fstrings, not modulo-formatting or .format

EDMarketConnector.py

@@ -99,6 +99,12 @@
         action='append',
     )
 
+    parser.add_argument(
+        '--trace-on',
+        help='Mark the selected trace logging as active.',
+        action='append',
+    )
+
     auth_options = parser.add_mutually_exclusive_group(required=False)
     auth_options.add_argument('--force-localserver-for-auth',
                               help='Force EDMC to use a localhost webserver for Frontier Auth callback',
@@ -146,6 +152,13 @@
 
         debug_webserver.run_listener(DEBUG_WEBSERVER_HOST, DEBUG_WEBSERVER_PORT)
 
+    if args.trace_on and len(args.trace_on) > 0:
+        import config as conf_module
+
+        conf_module.trace_on = [x.casefold() for x in args.trace_on]  # duplicate the list just in case
+        for d in conf_module.trace_on:
+            logger.info(f'marked {d} for TRACE')
+
     def handle_edmc_callback_or_foregrounding() -> None:  # noqa: CCR001
         """Handle any edmc:// auth callback, else foreground existing window."""
         logger.trace('Begin...')

config.py

@@ -41,6 +41,9 @@
 update_interval = 8*60*60
 # Providers marked to be in debug mode. Generally this is expected to switch to sending data to a log file
 debug_senders: List[str] = []
+# TRACE logging code that should actually be used.  Means not spamming it
+# *all* if only interested in some things.
+trace_on: List[str] = []
 
 # This must be done here in order to avoid an import cycle with EDMCLogging.
 # Other code should use EDMCLogging.get_main_logger

monitor.py

@@ -19,7 +19,7 @@
     import tkinter
 
 import util_ships
-from config import config
+from config import config, trace_on
 from edmc_data import edmc_suit_shortnames, edmc_suit_symbol_localised
 from EDMCLogging import get_main_logger
 
@@ -518,6 +518,8 @@ def parse_entry(self, line: bytes) -> MutableMapping[str, Any]:  # noqa: C901, C
                 self.live = True  # First event in 3.0
                 self.cmdr = entry['Name']
                 self.state['FID'] = entry['FID']
+                if 'startup' in trace_on:
+                    logger.trace(f'"Commander" event, {monitor.cmdr=}, {monitor.state["FID"]=}')
 
             elif event_type == 'loadgame':
                 # Odyssey Release Update 5 -- This contains data that doesn't match the format used in FileHeader above
@@ -559,6 +561,9 @@ def parse_entry(self, line: bytes) -> MutableMapping[str, Any]:  # noqa: C901, C
                 if entry.get('Ship') is not None and self._RE_SHIP_ONFOOT.search(entry['Ship']):
                     self.state['OnFoot'] = True
 
+                if 'startup' in trace_on:
+                    logger.trace(f'"LoadGame" event, {monitor.cmdr=}, {monitor.state["FID"]=}')
+
             elif event_type == 'newcommander':
                 self.cmdr = entry['Name']
                 self.group = None