ED/EDMarketConnector
1
0
Fork 0
mirror of https://github.com/EDCD/EDMarketConnector.git synced 2025-04-16 17:12:21 +03:00
Code Issues Projects Releases Wiki Activity

Merge pull request #1240 from A-UNDERSCORE-D/fix/1237/Ensure-we-can-quickly-find-all-the-current-in-code-trace_on-values

Browse Source 
Add helper methods around trace-on and override options
This commit is contained in:
Athanasius 2021-08-13 11:33:12 +01:00 committed by GitHub
commit 6eff033295
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 104 additions and 73 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

25
Contributing.md
View File

@ -409,20 +409,27 @@ In addition to that we utilise one of the user-defined levels as:
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 ...`
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:
still need to include `--trace`.
`--trace-on` stores its arguments in `config.trace_on`.
To make use of `--trace-on`, you can either check `config.trace_on` yourself:
```python
import config
if 'my-trace-rule' in config.trace_on:
logger.trace('my log message')
```
or you can use the helper method provided on `logger`:
```python
import config as conf_module # Necessary to see the same config.trace_on as elsewhere
logger.trace_if('my-trace-rule', 'my-log-message')
```
if 'edsm-cmdr-events' in conf_module.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.
This way you can set up TRACE logging that won't spam just because `--trace` is used.
---

28
EDMCLogging.py
View File

@ -48,6 +48,7 @@ from threading import get_native_id as thread_native_id
from traceback import print_exc
from typing import TYPE_CHECKING, Tuple, cast
import config as config_mod
from config import appcmdname, appname, config
# TODO: Tests:
@ -77,8 +78,11 @@ _default_loglevel = logging.DEBUG
# Define a TRACE level
LEVEL_TRACE = 5
LEVEL_TRACE_ALL = 3
logging.addLevelName(LEVEL_TRACE, "TRACE")
logging.addLevelName(LEVEL_TRACE_ALL, "TRACE_ALL")
logging.TRACE = LEVEL_TRACE # type: ignore
logging.TRACE_ALL = LEVEL_TRACE_ALL # type: ignore
logging.Logger.trace = lambda self, message, *args, **kwargs: self._log( # type: ignore
logging.TRACE, # type: ignore
message,
@ -86,6 +90,21 @@ logging.Logger.trace = lambda self, message, *args, **kwargs: self._log( # type
**kwargs
)
def _trace_if(self: logging.Logger, condition: str, message: str, *args, **kwargs) -> None:
if condition not in config_mod.trace_on:
self._log(logging.TRACE_ALL, message, args, **kwargs) # type: ignore # we added it
else:
# its in there, it gets to end up in regular TRACE
self._log(logging.TRACE, message, args, **kwargs) # type: ignore # we added it
logging.Logger.trace_if = _trace_if # type: ignore
# we cant hide this from `from xxx` imports and I'd really rather no-one other than `logging` had access to it
del _trace_if
if TYPE_CHECKING:
from types import FrameType
@ -98,6 +117,13 @@ if TYPE_CHECKING:
"""Fake trace method."""
return self._log(LEVEL_TRACE, message, args, **kwargs)
def trace_if(self, condition: str, message, *args, **kwargs) -> None:
"""Fake trace if method, traces only if condition exists in trace_on."""
if condition in config_mod.trace_on:
return self._log(LEVEL_TRACE, message, *args, **kwargs)
else:
return self._log(LEVEL_TRACE_ALL, message, *args, **kwargs)
class Logger:
"""
@ -492,7 +518,7 @@ class EDMCContextFilter(logging.Filter):
return module_name
def get_main_logger() -> 'LoggerMixin':
def get_main_logger(sublogger_name: str = '') -> 'LoggerMixin':
"""Return the correct logger for how the program is being run."""
if not os.getenv("EDMC_NO_UI"):
# GUI app being run

19
EDMarketConnector.py
View File

@ -76,6 +76,12 @@ if __name__ == '__main__': # noqa: C901
action='store_true',
)
parser.add_argument(
"--trace-all",
help="Disable trace-on functionality (show any and all trace messages, regardless of trace-on gates)",
action='store_true'
)
parser.add_argument(
'--reset-ui',
help='reset UI theme and transparency to defaults',
@ -101,7 +107,7 @@ if __name__ == '__main__': # noqa: C901
parser.add_argument(
'--trace-on',
help='Mark the selected trace logging as active.',
help='Mark the selected trace logging as active. * or all will ensure that every possible trace log appears (in the same way as --trace-all)',
action='append',
)
@ -123,9 +129,16 @@ if __name__ == '__main__': # noqa: C901
args = parser.parse_args()
level_to_set: Optional[int] = None
if args.trace:
logger.setLevel(logging.TRACE)
edmclogger.set_channels_loglevel(logging.TRACE)
level_to_set = logging.TRACE # type: ignore # it exists
if args.trace_all or '*' in args.trace_on or 'all' in args.trace_on:
level_to_set = logging.TRACE_ALL # type: ignore # it exists
if level_to_set is not None:
logger.setLevel(level_to_set)
edmclogger.set_channels_loglevel(level_to_set)
if args.force_localserver_for_auth:
config.set_auth_force_localserver()

12
monitor.py
View File

@ -18,13 +18,13 @@ from typing import Tuple
if TYPE_CHECKING:
import tkinter
import config as conf_module # Necessary to see the same config.trace_on as elsewhere
import util_ships
from config import config
from edmc_data import edmc_suit_shortnames, edmc_suit_symbol_localised
from EDMCLogging import get_main_logger
logger = get_main_logger()
STARTUP = 'startup'
if TYPE_CHECKING:
def _(x: str) -> str:
@ -519,8 +519,7 @@ class EDLogs(FileSystemEventHandler): # type: ignore # See below
self.live = True # First event in 3.0
self.cmdr = entry['Name']
self.state['FID'] = entry['FID']
if 'startup' in conf_module.trace_on:
logger.trace(f'"Commander" event, {monitor.cmdr=}, {monitor.state["FID"]=}')
logger.trace_if(STARTUP, 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
@ -531,9 +530,7 @@ class EDLogs(FileSystemEventHandler): # type: ignore # See below
self.cmdr = entry['Commander']
# 'Open', 'Solo', 'Group', or None for CQC (and Training - but no LoadGame event)
if not entry.get('Ship') and not entry.get('GameMode') or entry.get('GameMode', '').lower() == 'cqc':
if 'cqc-loadgame-events' in conf_module.trace_on:
logger.trace(f'loadgame to cqc: {entry}')
logger.trace_if('cqc-loadgame-events', f'loadgame to cqc: {entry}')
self.mode = 'CQC'
else:
@ -570,8 +567,7 @@ class EDLogs(FileSystemEventHandler): # type: ignore # See below
if entry.get('Ship') is not None and self._RE_SHIP_ONFOOT.search(entry['Ship']):
self.state['OnFoot'] = True
if 'startup' in conf_module.trace_on:
logger.trace(f'"LoadGame" event, {monitor.cmdr=}, {monitor.state["FID"]=}')
logger.trace_if(STARTUP, f'"LoadGame" event, {monitor.cmdr=}, {monitor.state["FID"]=}')
elif event_type == 'newcommander':
self.cmdr = entry['Name']

93
plugins/edsm.py
View File

@ -23,7 +23,7 @@ import killswitch
import myNotebook as nb # noqa: N813
import plug
from companion import CAPIData
from config import applongname, appversion, config, debug_senders, trace_on
from config import applongname, appversion, config, debug_senders
from edmc_data import DEBUG_WEBSERVER_HOST, DEBUG_WEBSERVER_PORT
from EDMCLogging import get_main_logger
from ttkHyperlinkLabel import HyperlinkLabel
@ -38,6 +38,10 @@ EDSM_POLL = 0.1
_TIMEOUT = 20
DISCARDED_EVENTS_SLEEP = 10
# trace-if events
CMDR_EVENTS = 'edsm-cmdr-events'
LOCATION_EVENTS = 'edsm-locations'
class This:
"""Holds module globals."""
@ -360,8 +364,7 @@ def credentials(cmdr: str) -> Optional[Tuple[str, str]]:
:param cmdr: The commander to get credentials for
:return: The credentials, or None
"""
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'{cmdr=}')
logger.trace_if(CMDR_EVENTS, f'{cmdr=}')
# Credentials for cmdr
if not cmdr:
@ -380,15 +383,12 @@ def credentials(cmdr: str) -> Optional[Tuple[str, str]]:
if idx >= len(edsm_usernames) or idx >= len(edsm_apikeys):
return None
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'{cmdr=}: returning ({edsm_usernames[idx]=}, {edsm_apikeys[idx]=})')
logger.trace_if(CMDR_EVENTS, f'{cmdr=}: returning ({edsm_usernames[idx]=}, {edsm_apikeys[idx]=})')
return (edsm_usernames[idx], edsm_apikeys[idx])
else:
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'{cmdr=}: returning None')
logger.trace_if(CMDR_EVENTS, f'{cmdr=}: returning None')
return None
@ -515,8 +515,7 @@ def journal_entry( # noqa: C901, CCR001
'Encoded': [{'Name': k, 'Count': v} for k, v in state['Encoded'].items()],
}
materials.update(transient)
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'"LoadGame" event, queueing Materials: {cmdr=}')
logger.trace_if(CMDR_EVENTS, f'"LoadGame" event, queueing Materials: {cmdr=}')
this.queue.put((cmdr, materials))
@ -524,8 +523,7 @@ def journal_entry( # noqa: C901, CCR001
# logger.trace(f'''{entry["event"]}
# Queueing: {entry!r}'''
# )
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'"{entry["event"]=}" event, queueing: {cmdr=}')
logger.trace_if(CMDR_EVENTS, f'"{entry["event"]=}" event, queueing: {cmdr=}')
this.queue.put((cmdr, entry))
@ -632,8 +630,7 @@ def worker() -> None: # noqa: CCR001 C901 # Cant be broken up currently
item: Optional[Tuple[str, Mapping[str, Any]]] = this.queue.get()
if item:
(cmdr, entry) = item
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'De-queued ({cmdr=}, {entry["event"]=})')
logger.trace_if(CMDR_EVENTS, f'De-queued ({cmdr=}, {entry["event"]=})')
else:
logger.debug('Empty queue message, setting closing = True')
@ -649,34 +646,30 @@ def worker() -> None: # noqa: CCR001 C901 # Cant be broken up currently
break
try:
if item and entry['event'] not in this.discarded_events:
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'({cmdr=}, {entry["event"]=}): not in discarded_events, appending to pending')
logger.trace_if(
CMDR_EVENTS, f'({cmdr=}, {entry["event"]=}): not in discarded_events, appending to pending')
pending.append(entry)
if pending and should_send(pending, entry['event']):
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'({cmdr=}, {entry["event"]=}): should_send() said True')
pendings = [f"{p}\n" for p in pending]
logger.trace(f'pending contains:\n{pendings}')
logger.trace_if(CMDR_EVENTS, f'({cmdr=}, {entry["event"]=}): should_send() said True')
logger.trace_if(CMDR_EVENTS, f'pending contains:\n{chr(0x0A).join(str(p) for p in pending)}')
if 'edsm-locations' in trace_on and \
any(p for p in pending if p['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked')):
logger.trace("pending has at least one of "
"('CarrierJump', 'FSDJump', 'Location', 'Docked')"
" and it passed should_send()")
if any(p for p in pending if p['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked')):
logger.trace_if(LOCATION_EVENTS, "pending has at least one of "
"('CarrierJump', 'FSDJump', 'Location', 'Docked')"
" and it passed should_send()")
for p in pending:
if p['event'] in ('Location'):
logger.trace('"Location" event in pending passed should_send(), '
f'timestamp: {p["timestamp"]}')
logger.trace_if(LOCATION_EVENTS, '"Location" event in pending passed should_send(), '
f'timestamp: {p["timestamp"]}')
creds = credentials(cmdr) # TODO: possibly unbound
if creds is None:
raise ValueError("Unexpected lack of credentials")
username, apikey = creds
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'({cmdr=}, {entry["event"]=}): Using {username=} from credentials()')
logger.trace_if(CMDR_EVENTS, f'({cmdr=}, {entry["event"]=}): Using {username=} from credentials()')
data = {
'commanderName': username.encode('utf-8'),
@ -686,23 +679,26 @@ def worker() -> None: # noqa: CCR001 C901 # Cant be broken up currently
'message': json.dumps(pending, ensure_ascii=False).encode('utf-8'),
}
if 'edsm-locations' in trace_on and \
any(p for p in pending if p['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked')):
if any(p for p in pending if p['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked')):
data_elided = data.copy()
data_elided['apiKey'] = '<elided>'
logger.trace(
"pending has at least one of "
"('CarrierJump', 'FSDJump', 'Location', 'Docked')"
logger.trace_if(
LOCATION_EVENTS,
"pending has at least one of ('CarrierJump', 'FSDJump', 'Location', 'Docked')"
" Attempting API call with the following events:"
)
for p in pending:
logger.trace(f"Event: {p!r}")
logger.trace_if(LOCATION_EVENTS, f"Event: {p!r}")
if p['event'] in ('Location'):
logger.trace('Attempting API call for "Location" event with timestamp: '
f'{p["timestamp"]}')
logger.trace_if(
LOCATION_EVENTS,
f'Attempting API call for "Location" event with timestamp: {p["timestamp"]}'
)
logger.trace(f'Overall POST data (elided) is:\n{data_elided}')
logger.trace_if(
LOCATION_EVENTS, f'Overall POST data (elided) is:\n{json.dumps(data_elided, indent=2)}'
)
r = this.session.post(TARGET_URL, data=data, timeout=_TIMEOUT)
# logger.trace(f'API response content: {r.content}')
@ -761,8 +757,7 @@ def worker() -> None: # noqa: CCR001 C901 # Cant be broken up currently
if entry['event'].lower() in ('shutdown', 'commander', 'fileheader'):
# Game shutdown or new login so we MUST not hang on to pending
pending = []
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'Blanked pending because of event: {entry["event"]}')
logger.trace_if(CMDR_EVENTS, f'Blanked pending because of event: {entry["event"]}')
if closing:
logger.debug('closing, so returning.')
@ -781,8 +776,7 @@ def should_send(entries: List[Mapping[str, Any]], event: str) -> bool: # noqa:
"""
# We MUST flush pending on logout, in case new login is a different Commander
if event.lower() in ('shutdown', 'fileheader'):
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'True because {event=}')
logger.trace_if(CMDR_EVENTS, f'True because {event=}')
return True
@ -791,8 +785,7 @@ def should_send(entries: List[Mapping[str, Any]], event: str) -> bool: # noqa:
if entries and entries[-1]['event'] == 'Scan':
this.navbeaconscan -= 1
if this.navbeaconscan:
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'False because {this.navbeaconscan=}')
logger.trace_if(CMDR_EVENTS, f'False because {this.navbeaconscan=}')
return False
@ -808,8 +801,7 @@ def should_send(entries: List[Mapping[str, Any]], event: str) -> bool: # noqa:
# Cargo is the last event on startup, unless starting when docked in which case Docked is the last event
this.newgame = False
this.newgame_docked = False
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'True because {entry["event"]=}')
logger.trace_if(CMDR_EVENTS, f'True because {entry["event"]=}')
return True
@ -820,17 +812,14 @@ def should_send(entries: List[Mapping[str, Any]], event: str) -> bool: # noqa:
'CommunityGoal', # Spammed periodically
'ModuleBuy', 'ModuleSell', 'ModuleSwap', # will be shortly followed by "Loadout"
'ShipyardBuy', 'ShipyardNew', 'ShipyardSwap'): # "
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'True because {entry["event"]=}')
logger.trace_if(CMDR_EVENTS, f'True because {entry["event"]=}')
return True
else:
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'{entry["event"]=}, {this.newgame_docked=}')
logger.trace_if(CMDR_EVENTS, f'{entry["event"]=}, {this.newgame_docked=}')
if 'edsm-cmdr-events' in trace_on:
logger.trace(f'False as default: {this.newgame_docked=}')
logger.trace_if(CMDR_EVENTS, f'False as default: {this.newgame_docked=}')
return False