Make logging optionally remove global handlers added by (shitty) pip
[python_utils.git] / bootstrap.py
1 #!/usr/bin/env python3
2
3 import functools
4 import logging
5 import os
6 from inspect import stack
7 import sys
8
9 # This module is commonly used by others in here and should avoid
10 # taking any unnecessary dependencies back on them.
11
12 from argparse_utils import ActionNoYes
13 import config
14 import logging_utils
15
16 logger = logging.getLogger(__name__)
17
18 args = config.add_commandline_args(
19     f'Bootstrap ({__file__})',
20     'Args related to python program bootstrapper and Swiss army knife')
21 args.add_argument(
22     '--debug_unhandled_exceptions',
23     action=ActionNoYes,
24     default=False,
25     help='Break into pdb on top level unhandled exceptions.'
26 )
27 args.add_argument(
28     '--show_random_seed',
29     action=ActionNoYes,
30     default=False,
31     help='Should we display (and log.debug) the global random seed?'
32 )
33 args.add_argument(
34     '--set_random_seed',
35     type=int,
36     nargs=1,
37     default=None,
38     metavar='SEED_INT',
39     help='Override the global random seed with a particular number.'
40 )
41 args.add_argument(
42     '--dump_all_objects',
43     action=ActionNoYes,
44     default=False,
45     help='Should we dump the Python import tree before main?'
46 )
47 args.add_argument(
48     '--audit_import_events',
49     action=ActionNoYes,
50     default=False,
51     help='Should we audit all import events?',
52 )
53
54
55 original_hook = sys.excepthook
56
57
58 def handle_uncaught_exception(exc_type, exc_value, exc_tb):
59     """
60     Top-level exception handler for exceptions that make it past any exception
61     handlers in the python code being run.  Logs the error and stacktrace then
62     maybe attaches a debugger.
63     """
64     global original_hook
65     msg = f'Unhandled top level exception {exc_type}'
66     logger.exception(msg)
67     print(msg, file=sys.stderr)
68     if issubclass(exc_type, KeyboardInterrupt):
69         sys.__excepthook__(exc_type, exc_value, exc_tb)
70         return
71     else:
72         if (
73                 not sys.stderr.isatty() or
74                 not sys.stdin.isatty()
75         ):
76             # stdin or stderr is redirected, just do the normal thing
77             original_hook(exc_type, exc_value, exc_tb)
78         else:
79             # a terminal is attached and stderr is not redirected, maybe debug.
80             import traceback
81             traceback.print_exception(exc_type, exc_value, exc_tb)
82             if config.config['debug_unhandled_exceptions']:
83                 import pdb
84                 logger.info("Invoking the debugger...")
85                 pdb.pm()
86             else:
87                 original_hook(exc_type, exc_value, exc_tb)
88
89
90 class ImportInterceptor(object):
91     def __init__(self):
92         import collect.trie
93         self.module_by_filename_cache = {}
94         self.repopulate_modules_by_filename()
95         self.tree = collect.trie.Trie()
96         self.tree_node_by_module = {}
97
98     def repopulate_modules_by_filename(self):
99         self.module_by_filename_cache.clear()
100         for mod in sys.modules:
101             if hasattr(sys.modules[mod], '__file__'):
102                 fname = getattr(sys.modules[mod], '__file__')
103             else:
104                 fname = 'unknown'
105             self.module_by_filename_cache[fname] = mod
106
107     def should_ignore_filename(self, filename: str) -> bool:
108         return 'importlib' in filename or 'six.py' in filename
109
110     def find_spec(self, loaded_module, path=None, target=None):
111         s = stack()
112         for x in range(3, len(s)):
113             filename = s[x].filename
114             if self.should_ignore_filename(filename):
115                 continue
116
117             loading_function = s[x].function
118             if filename in self.module_by_filename_cache:
119                 loading_module = self.module_by_filename_cache[filename]
120             else:
121                 self.repopulate_modules_by_filename()
122                 loading_module = self.module_by_filename_cache.get(filename, 'unknown')
123
124             path = self.tree_node_by_module.get(loading_module, [])
125             path.extend([loaded_module])
126             self.tree.insert(path)
127             self.tree_node_by_module[loading_module] = path
128
129             msg = f'*** Import {loaded_module} from {filename}:{s[x].lineno} in {loading_module}::{loading_function}'
130             logger.debug(msg)
131             print(msg)
132             return
133         msg = f'*** Import {loaded_module} from ?????'
134         logger.debug(msg)
135         print(msg)
136
137     def find_importer(self, module: str):
138         if module in self.tree_node_by_module:
139             node = self.tree_node_by_module[module]
140             return node
141         return []
142
143
144 # TODO: test this with python 3.8+
145 def audit_import_events(event, args):
146     print(event)
147     print(args)
148
149
150 # Audit import events?  Note: this runs early in the lifetime of the
151 # process (assuming that import bootstrap happens early); config has
152 # (probably) not yet been loaded or parsed the commandline.  Also,
153 # some things have probably already been imported while we weren't
154 # watching so this information may be incomplete.
155 #
156 # Also note: move bootstrap up in the global import list to catch
157 # more import events and have a more complete record.
158 import_interceptor = None
159 for arg in sys.argv:
160     if arg == '--audit_import_events':
161         if not hasattr(sys, 'frozen'):
162             if (
163                     sys.version_info[0] == 3
164                     and sys.version_info[1] < 8
165             ):
166                 import_interceptor = ImportInterceptor()
167                 sys.meta_path = [import_interceptor] + sys.meta_path
168             else:
169                 sys.addaudithook(audit_import_events)
170
171
172 def dump_all_objects() -> None:
173     global import_interceptor
174     messages = {}
175     all_modules = sys.modules
176     for obj in object.__subclasses__():
177         if not hasattr(obj, '__name__'):
178             continue
179         klass = obj.__name__
180         if not hasattr(obj, '__module__'):
181             continue
182         class_mod_name = obj.__module__
183         if class_mod_name in all_modules:
184             mod = all_modules[class_mod_name]
185             if not hasattr(mod, '__name__'):
186                 mod_name = class_mod_name
187             else:
188                 mod_name = mod.__name__
189             if hasattr(mod, '__file__'):
190                 mod_file = mod.__file__
191             else:
192                 mod_file = 'unknown'
193             if import_interceptor is not None:
194                 import_path = import_interceptor.find_importer(mod_name)
195             else:
196                 import_path = 'unknown'
197             msg = f'{class_mod_name}::{klass} ({mod_file})'
198             if import_path != 'unknown' and len(import_path) > 0:
199                 msg += f' imported by {import_path}'
200             messages[f'{class_mod_name}::{klass}'] = msg
201     for x in sorted(messages.keys()):
202         logger.debug(messages[x])
203         print(messages[x])
204
205
206 def initialize(entry_point):
207     """
208     Remember to initialize config, initialize logging, set/log a random
209     seed, etc... before running main.
210
211     """
212     @functools.wraps(entry_point)
213     def initialize_wrapper(*args, **kwargs):
214         # Hook top level unhandled exceptions, maybe invoke debugger.
215         if sys.excepthook == sys.__excepthook__:
216             sys.excepthook = handle_uncaught_exception
217
218         # Try to figure out the name of the program entry point.  Then
219         # parse configuration (based on cmdline flags, environment vars
220         # etc...)
221         if (
222                 '__globals__' in entry_point.__dict__ and
223                 '__file__' in entry_point.__globals__
224         ):
225             config.parse(entry_point.__globals__['__file__'])
226         else:
227             config.parse(None)
228
229         # Initialize logging... and log some remembered messages from
230         # config module.
231         logging_utils.initialize_logging(logging.getLogger())
232         config.late_logging()
233
234         # Allow programs that don't bother to override the random seed
235         # to be replayed via the commandline.
236         import random
237         random_seed = config.config['set_random_seed']
238         if random_seed is not None:
239             random_seed = random_seed[0]
240         else:
241             random_seed = int.from_bytes(os.urandom(4), 'little')
242
243         if config.config['show_random_seed']:
244             msg = f'Global random seed is: {random_seed}'
245             logger.debug(msg)
246             print(msg)
247         random.seed(random_seed)
248
249         # Do it, invoke the user's code.  Pay attention to how long it takes.
250         logger.debug(f'Starting {entry_point.__name__} (program entry point)')
251         ret = None
252         import stopwatch
253         with stopwatch.Timer() as t:
254             ret = entry_point(*args, **kwargs)
255         logger.debug(
256             f'{entry_point.__name__} (program entry point) returned {ret}.'
257         )
258
259         if config.config['dump_all_objects']:
260             dump_all_objects()
261
262         if config.config['audit_import_events']:
263             global import_interceptor
264             if import_interceptor is not None:
265                 print(import_interceptor.tree)
266
267         walltime = t()
268         (utime, stime, cutime, cstime, elapsed_time) = os.times()
269         logger.debug('\n'
270                      f'user: {utime}s\n'
271                      f'system: {stime}s\n'
272                      f'child user: {cutime}s\n'
273                      f'child system: {cstime}s\n'
274                      f'machine uptime: {elapsed_time}s\n'
275                      f'walltime: {walltime}s')
276
277         # If it doesn't return cleanly, call attention to the return value.
278         if ret is not None and ret != 0:
279             logger.error(f'Exit {ret}')
280         else:
281             logger.debug(f'Exit {ret}')
282         sys.exit(ret)
283     return initialize_wrapper