diff --git a/Contributing.md b/Contributing.md index 02e02b58..54e39907 100644 --- a/Contributing.md +++ b/Contributing.md @@ -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. --- diff --git a/EDMCLogging.py b/EDMCLogging.py index 6633064e..c6928a63 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -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 diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 9ead323c..aa80e4c2 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -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() diff --git a/monitor.py b/monitor.py index c91c0567..dac75ae9 100644 --- a/monitor.py +++ b/monitor.py @@ -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'] diff --git a/plugins/edsm.py b/plugins/edsm.py index 9ad31c71..76ac203e 100644 --- a/plugins/edsm.py +++ b/plugins/edsm.py @@ -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'] = '' - 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