From 76eba3be03ce3c41df5639a4a73a4d7ffd8722dc Mon Sep 17 00:00:00 2001 From: Grigori Fursin Date: Thu, 17 Oct 2024 11:25:29 +0200 Subject: [PATCH 1/6] V3.2.4 - CMX: improved logging - CMX: improved error handling (show module path and line number) --- cm/CHANGES.md | 4 ++ cm/cmind/__init__.py | 3 +- cm/cmind/cli.py | 2 +- cm/cmind/config.py | 1 + cm/cmind/core.py | 139 +++++++++++++++++++++++++++++++++++++++---- cm/cmind/utils.py | 7 ++- 6 files changed, 139 insertions(+), 17 deletions(-) diff --git a/cm/CHANGES.md b/cm/CHANGES.md index f39ad0dc2..cd843fef2 100644 --- a/cm/CHANGES.md +++ b/cm/CHANGES.md @@ -1,3 +1,7 @@ +## V3.2.4 + - CMX: improved logging + - CMX: improved error handling (show module path and line number) + ## V3.2.3 - added --new_branch to `cm pull repo` and `cm checkout repo` - fixed a bug in `cm show repo` (removed dependency on cm4mlops diff --git a/cm/cmind/__init__.py b/cm/cmind/__init__.py index d1f4e1a27..8319cb86c 100644 --- a/cm/cmind/__init__.py +++ b/cm/cmind/__init__.py @@ -2,10 +2,11 @@ # # Written by Grigori Fursin -__version__ = "3.2.3" +__version__ = "3.2.4" from cmind.core import access from cmind.core import x from cmind.core import error +from cmind.core import errorx from cmind.core import halt from cmind.core import CM diff --git a/cm/cmind/cli.py b/cm/cmind/cli.py index d62fbc90e..7e03d2347 100644 --- a/cm/cmind/cli.py +++ b/cm/cmind/cli.py @@ -84,7 +84,7 @@ def runx(argv = None): r = cm.x(argv, out='con') if r['return']>0 and (cm.output is None or cm.output == 'con'): - cm.error(r) + cm.errorx(r) sys.exit(r['return']) diff --git a/cm/cmind/config.py b/cm/cmind/config.py index bf18f7832..7b5644224 100644 --- a/cm/cmind/config.py +++ b/cm/cmind/config.py @@ -37,6 +37,7 @@ def __init__(self, config_file = None): "flag_help2": "help", "error_prefix": "CM error:", + "error_prefix2": "CMX detected an issue", "info_cli": "cm {action} {automation} {artifact(s)} {flags} @input.yaml @input.json", "info_clix": "cmx {action} {automation} {artifact(s)} {CMX control flags (-)} {CMX automation flags (--)}", diff --git a/cm/cmind/core.py b/cm/cmind/core.py index e903174ad..f563fbfa1 100644 --- a/cm/cmind/core.py +++ b/cm/cmind/core.py @@ -140,6 +140,116 @@ def error(self, r): return r + ############################################################ + def errorx(self, r): + """ + If r['return']>0: print CM error and raise error if in debugging mode + + Args: + r (dict): output from CM function with "return" and "error" + + Returns: + (dict): r + + """ + + import os + + if r['return']>0: + if self.debug: + raise Exception(r['error']) + + module_path = r.get('module_path', '') + lineno = r.get('lineno', '') + + message = '' + + if not self.logger == None or (module_path != '' and lineno != ''): + call_stack = self.state.get('call_stack', []) + + if not self.logger == None: + + self.log(f"x error call stack: {call_stack}", "debug") + self.log(f"x error: {r}", "debug") + + sys.stderr.write('='*60 + '\n') + + if not self.logger == None: + sys.stderr.write('CMX call stack:\n') + + for cs in call_stack: + sys.stderr.write(f' * {cs}\n') + + message += '\n' + else: + message += '\n' + + message += self.cfg['error_prefix2'] + + if module_path != '' and lineno !='': + message += f' in {module_path} ({lineno}):\n\n' + else: + message += ': ' + + message += r['error'] + '\n' + + sys.stderr.write(message) + + return r + + ############################################################ + def prepare_error(self, returncode, error): + """ + Prepare error dictionary with the module and line number of an error + + Args: + returncode (int): CMX returncode + error (str): error message + + Returns: + (dict): r + return (int) + error (str) + module_path (str): path to module + lineno (int): line number + + """ + + from inspect import getframeinfo, stack + + caller = getframeinfo(stack()[1][0]) + + return {'return': returncode, + 'error': error, + 'module_path': caller.filename, + 'lineno': caller.lineno} + + ############################################################ + def embed_error(self, r): + """ + Embed module and line number to an error + + Args: + r (dict): CM return dict + + Returns: + (dict): r + return (int) + error (str) + module_path (str): path to module + lineno (int): line number + + """ + + from inspect import getframeinfo, stack + + caller = getframeinfo(stack()[1][0]) + + r['module_path'] = caller.filename + r['lineno'] = caller.lineno + + return r + ############################################################ def halt(self, r): """ @@ -849,18 +959,6 @@ def x(self, i, out = None): meta = r) if r['return'] >0: - if r['return'] > 32: - print ('') - print ('CM Error Call Stack:') - - call_stack = self.state['call_stack'] - - for cs in call_stack: - print (f' {cs}') - - self.log(f"x error call stack: {call_stack}", "debug") - self.log(f"x error: {r}", "debug") - if use_raise: raise Exception(r['error']) @@ -1518,6 +1616,23 @@ def error(i): return cm.error(i) +############################################################ +def errorx(i): + """ + Automatically initialize CM and print error if needed + without the need to initialize and customize CM class. + Useful for Python automation scripts. + + See CM.error function for more details. + """ + + global cm + + if cm is None: + cm=CM() + + return cm.errorx(i) + ############################################################ def halt(i): """ diff --git a/cm/cmind/utils.py b/cm/cmind/utils.py index 56c19f2c9..c8a964ed5 100644 --- a/cm/cmind/utils.py +++ b/cm/cmind/utils.py @@ -1928,7 +1928,7 @@ def convert_dictionary(d, key, sub = True): return dd ############################################################################## -def test_input(i, module): +def test_input(i): """ Test if input has keys and report them as error """ @@ -1939,9 +1939,10 @@ def test_input(i, module): unknown_keys = i.keys() unknown_keys_str = ', '.join(unknown_keys) + x = '' if len(unknown_keys) == 1 else 's' + r = {'return': 1, - 'error': 'unknown input key(s) "{}" in module {}'.format(unknown_keys_str, module), - 'module': module, + 'error': f'unknown input key{x}: {unknown_keys_str}', 'unknown_keys': unknown_keys, 'unknown_keys_str': unknown_keys_str} From aea342e31023d339e32c89b50d383f0e4faf7e5b Mon Sep 17 00:00:00 2001 From: Grigori Fursin Date: Fri, 18 Oct 2024 18:04:32 +0200 Subject: [PATCH 2/6] Added self-time: https://github.com/mlcommons/ck/issues/1332 (cmx -time) --- cm/cmind/__init__.py | 2 +- cm/cmind/core.py | 17 +++++++++++++++-- 2 files changed, 16 insertions(+), 3 deletions(-) diff --git a/cm/cmind/__init__.py b/cm/cmind/__init__.py index 8319cb86c..a99021d8c 100644 --- a/cm/cmind/__init__.py +++ b/cm/cmind/__init__.py @@ -2,7 +2,7 @@ # # Written by Grigori Fursin -__version__ = "3.2.4" +__version__ = "3.2.4.1" from cmind.core import access from cmind.core import x diff --git a/cm/cmind/core.py b/cm/cmind/core.py index f563fbfa1..85e18e39f 100644 --- a/cm/cmind/core.py +++ b/cm/cmind/core.py @@ -842,7 +842,7 @@ def x(self, i, out = None): 'h', 'help', 'version', 'out', 'j', 'json', 'save_to_json_file', 'save_to_yaml_file', 'common', 'ignore_inheritance', 'log', 'logfile', 'raise', 'repro', - 'f']] + 'f', 'time']] if len(unknown_control_flags)>0: unknown_control_flags_str = ','.join(unknown_control_flags) @@ -855,6 +855,11 @@ def x(self, i, out = None): if control.pop('f', ''): i['f'] = True + self_time = control.pop('time', False) + if not x_was_called and self_time: + import time + self_time1 = time.time() + # Check repro use_log = str(control_flags.pop('log', '')).strip().lower() log_file = control_flags.pop('logfile', '') @@ -939,6 +944,14 @@ def x(self, i, out = None): # Very first call (not recursive) # Check if output to json and save file + if self_time: + self_time = time.time() - self_time1 + r['self_time'] = self_time + + if self.output == 'con': + print ('') + print ('CMX elapsed time: {:.3f} sec.'.format(self_time)) + if self.output == 'json': utils.dump_safe_json(r) @@ -1211,7 +1224,7 @@ def _x(self, i, control): return {'return':4, 'error':'automation meta not found in {}'.format(automation_path)} # Load artifact class - r=utils.load_yaml_and_json(automation_path_meta) + r = utils.load_yaml_and_json(automation_path_meta) if r['return']>0: return r automation_meta = r['meta'] From 93c2eab854ac7adccf17032e02a25953c0baad16 Mon Sep 17 00:00:00 2001 From: Grigori Fursin Date: Fri, 18 Oct 2024 18:18:43 +0200 Subject: [PATCH 3/6] Added self-profile (-profile): https://github.com/mlcommons/ck/issues/1331 --- cm/cmind/core.py | 24 ++++++++++++++++++++++-- 1 file changed, 22 insertions(+), 2 deletions(-) diff --git a/cm/cmind/core.py b/cm/cmind/core.py index 85e18e39f..69411b639 100644 --- a/cm/cmind/core.py +++ b/cm/cmind/core.py @@ -842,7 +842,7 @@ def x(self, i, out = None): 'h', 'help', 'version', 'out', 'j', 'json', 'save_to_json_file', 'save_to_yaml_file', 'common', 'ignore_inheritance', 'log', 'logfile', 'raise', 'repro', - 'f', 'time']] + 'f', 'time', 'profile']] if len(unknown_control_flags)>0: unknown_control_flags_str = ','.join(unknown_control_flags) @@ -855,11 +855,13 @@ def x(self, i, out = None): if control.pop('f', ''): i['f'] = True - self_time = control.pop('time', False) + self_time = control.get('time', False) if not x_was_called and self_time: import time self_time1 = time.time() + self_profile = control.get('profile', False) + # Check repro use_log = str(control_flags.pop('log', '')).strip().lower() log_file = control_flags.pop('logfile', '') @@ -933,6 +935,13 @@ def x(self, i, out = None): self.log(f"x input: {spaces} ({i})", "debug") # Call access helper + if not x_was_called and self_profile: + # https://docs.python.org/3/library/profile.html#module-cProfile + import cProfile, pstats, io + from pstats import SortKey + profile = cProfile.Profile() + profile.enable() + r = self._x(i, control) if not self.logger == None: @@ -941,6 +950,17 @@ def x(self, i, out = None): self.state['recursion'] = recursion if not x_was_called: + if self_profile: + profile.disable() + s = io.StringIO() + sortby = SortKey.CUMULATIVE + ps = pstats.Stats(profile, stream=s).sort_stats(sortby) + ps.print_stats(32) + print ('') + print ('CMX profile:') + print ('') + print (s.getvalue()) + # Very first call (not recursive) # Check if output to json and save file From 100bc66230e02bb03883c7ec77286f4516b1e3c6 Mon Sep 17 00:00:00 2001 From: Grigori Fursin Date: Fri, 18 Oct 2024 18:19:36 +0200 Subject: [PATCH 4/6] improve help --- cm/cmind/core.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/cm/cmind/core.py b/cm/cmind/core.py index 69411b639..14ffdce1f 100644 --- a/cm/cmind/core.py +++ b/cm/cmind/core.py @@ -1071,6 +1071,8 @@ def _x(self, i, control): print (' -log={info (default) | debug | warning | error} - log level') print (' -logfile={path to log file} - record log to file instead of console') print (' -raise - raise Python error when automation action fails') + print (' -time - print elapsed time for a given automation') + print (' -profile - profile a given automation') print (' -repro - record various info to the cmx-repro directory to replay CMX command') print ('') print ('Check https://github.com/mlcommons/ck/tree/master/cm/docs/cmx for more details.') From bc800cfb92716677a6a1ab118c6b0e1c7c4996be Mon Sep 17 00:00:00 2001 From: Grigori Fursin Date: Sat, 19 Oct 2024 15:04:01 +0200 Subject: [PATCH 5/6] Fixed bug when detecting unknown control flag: https://github.com/mlcommons/ck/issues/1333 --- cm/CHANGES.md | 1 + cm/cmind/core.py | 12 +++++++++--- 2 files changed, 10 insertions(+), 3 deletions(-) diff --git a/cm/CHANGES.md b/cm/CHANGES.md index cd843fef2..125eb93cb 100644 --- a/cm/CHANGES.md +++ b/cm/CHANGES.md @@ -1,6 +1,7 @@ ## V3.2.4 - CMX: improved logging - CMX: improved error handling (show module path and line number) + - CMX: fixed bug when detecting unknown control flag ## V3.2.3 - added --new_branch to `cm pull repo` and `cm checkout repo` diff --git a/cm/cmind/core.py b/cm/cmind/core.py index 14ffdce1f..8ecca0566 100644 --- a/cm/cmind/core.py +++ b/cm/cmind/core.py @@ -844,11 +844,13 @@ def x(self, i, out = None): 'ignore_inheritance', 'log', 'logfile', 'raise', 'repro', 'f', 'time', 'profile']] + delayed_error = '' + if len(unknown_control_flags)>0: unknown_control_flags_str = ','.join(unknown_control_flags) - print (f'Unknown control flag(s): {unknown_control_flags_str}') - print ('') + delayed_error = f'Unknown control flag(s): {unknown_control_flags_str}' + # Force print help control['h'] = True @@ -943,7 +945,11 @@ def x(self, i, out = None): profile.enable() r = self._x(i, control) - + + if delayed_error != '' and r['return'] == 0: + r['return'] = 1 + r['error'] = delayed_error + if not self.logger == None: self.log(f"x output: {r}", "debug") From ce4738a1be0d86964ce8f7aec46617c1a1e08244 Mon Sep 17 00:00:00 2001 From: Grigori Fursin Date: Sat, 19 Oct 2024 18:50:47 +0200 Subject: [PATCH 6/6] V3.2.5 - CMX: improved logging - CMX: improved error handling (show module path and line number) - CMX: fixed bug when detecting unknown control flag - CMX: do not change output to json if -j or --json just print json in the end ... --- cm/CHANGES.md | 4 +++- cm/cmind/__init__.py | 2 +- cm/cmind/core.py | 26 ++++++++++++++++++++------ 3 files changed, 24 insertions(+), 8 deletions(-) diff --git a/cm/CHANGES.md b/cm/CHANGES.md index 125eb93cb..57b892232 100644 --- a/cm/CHANGES.md +++ b/cm/CHANGES.md @@ -1,7 +1,9 @@ -## V3.2.4 +## V3.2.5 - CMX: improved logging - CMX: improved error handling (show module path and line number) - CMX: fixed bug when detecting unknown control flag + - CMX: do not change output to json if -j or --json + just print json in the end ... ## V3.2.3 - added --new_branch to `cm pull repo` and `cm checkout repo` diff --git a/cm/cmind/__init__.py b/cm/cmind/__init__.py index a99021d8c..f7f78e1f5 100644 --- a/cm/cmind/__init__.py +++ b/cm/cmind/__init__.py @@ -2,7 +2,7 @@ # # Written by Grigori Fursin -__version__ = "3.2.4.1" +__version__ = "3.2.5" from cmind.core import access from cmind.core import x diff --git a/cm/cmind/core.py b/cm/cmind/core.py index 8ecca0566..8e3577ce1 100644 --- a/cm/cmind/core.py +++ b/cm/cmind/core.py @@ -616,7 +616,7 @@ def access(self, i, out = None): if automation=='': return {'return':4, 'error':'automation was not specified'} else: - return {'return':4, 'error':'automation {} not found'.format(automation)} + return {'return':4, 'error':'automation "{}" not found'.format(automation)} # If no automation was found or we force common automation if use_common_automation or len(automation_lst)==0: @@ -857,6 +857,8 @@ def x(self, i, out = None): if control.pop('f', ''): i['f'] = True + output_json = (control.get('j', False) or control.get('json', False)) + self_time = control.get('time', False) if not x_was_called and self_time: import time @@ -978,7 +980,7 @@ def x(self, i, out = None): print ('') print ('CMX elapsed time: {:.3f} sec.'.format(self_time)) - if self.output == 'json': + if output_json: utils.dump_safe_json(r) # Restore directory of call @@ -1014,9 +1016,10 @@ def _x(self, i, control): if output == True: output = 'con' - # Check and force json console output - if control.get('j', False) or control.get('json', False): - output = 'json' +# Changed in v3.2.5 +# # Check and force json console output +# if control.get('j', False) or control.get('json', False): +# output = 'json' # Set self.output to the output of the very first access # to print error in the end if needed @@ -1050,6 +1053,17 @@ def _x(self, i, control): elif action == 'init' and automation == '': automation = 'core' + # Can add popular shortcuts + elif action == 'ff': + task = '' + if automation != '' and (' ' in automation or ',' in automation): + task = automation + if ' ' in automation: task = automation.replace(' ',',') + i['task'] = task + automation = 'flex.flow' + action = 'run' + i['automation'] = automation + i['action'] = action # Print basic help if action == '' extra_help = True if action == 'help' and automation == '' else False @@ -1291,7 +1305,7 @@ def _x(self, i, control): if automation=='': return {'return':4, 'error':'automation was not specified'} else: - return {'return':4, 'error':f'automation {automation} not found'} + return {'return':4, 'error':f'automation "{automation}" not found'} # If no automation was found or we force common automation loaded_common_automation = False