Coverage for /pythoncovmergedfiles/medio/medio/usr/local/lib/python3.8/site-packages/dill/logger.py: 36%

1#!/usr/bin/env python 

2# -*- coding: utf-8 -*- 

3# 

4# Author: Leonardo Gama (@leogama) 

5# Copyright (c) 2022 The Uncertainty Quantification Foundation. 

6# License: 3-clause BSD. The full license text is available at: 

7# - https://github.com/uqfoundation/dill/blob/master/LICENSE 

8""" 

9Logging utilities for dill. 

10 

11The 'logger' object is dill's top-level logger. 

12 

13The 'adapter' object wraps the logger and implements a 'trace()' method that 

14generates a detailed tree-style trace for the pickling call at log level INFO. 

15 

16The 'trace()' function sets and resets dill's logger log level, enabling and 

17disabling the pickling trace. 

18 

19The trace shows a tree structure depicting the depth of each object serialized 

20*with dill save functions*, but not the ones that use save functions from 

21'pickle._Pickler.dispatch'. If the information is available, it also displays 

22the size in bytes that the object contributed to the pickle stream (including 

23its child objects). Sample trace output: 

24 

25 >>> import dill, dill.tests 

26 >>> dill.detect.trace(True) 

27 >>> dill.dump_session(main=dill.tests) 

28 ┬ M1: <module 'dill.tests' from '.../dill/tests/__init__.py'> 

29 ├┬ F2: <function _import_module at 0x7f0d2dce1b80> 

30 │└ # F2 [32 B] 

31 ├┬ D2: <dict object at 0x7f0d2e98a540> 

32 │├┬ T4: <class '_frozen_importlib.ModuleSpec'> 

33 ││└ # T4 [35 B] 

34 │├┬ D2: <dict object at 0x7f0d2ef0e8c0> 

35 ││├┬ T4: <class '_frozen_importlib_external.SourceFileLoader'> 

36 │││└ # T4 [50 B] 

37 ││├┬ D2: <dict object at 0x7f0d2e988a40> 

38 │││└ # D2 [84 B] 

39 ││└ # D2 [413 B] 

40 │└ # D2 [763 B] 

41 └ # M1 [813 B] 

42""" 

43 

44__all__ = ['adapter', 'logger', 'trace'] 

45 

46import codecs 

47import contextlib 

48import locale 

49import logging 

50import math 

51import os 

52from functools import partial 

53from typing import TextIO, Union 

54 

55import dill 

56 

57# Tree drawing characters: Unicode to ASCII map. 

58ASCII_MAP = str.maketrans({"│": "|", "├": "|", "┬": "+", "└": "`"}) 

59 

60## Notes about the design choices ## 

61 

62# Here is some domumentation of the Standard Library's logging internals that 

63# can't be found completely in the official documentation. dill's logger is 

64# obtained by calling logging.getLogger('dill') and therefore is an instance of 

65# logging.getLoggerClass() at the call time. As this is controlled by the user, 

66# in order to add some functionality to it it's necessary to use a LoggerAdapter 

67# to wrap it, overriding some of the adapter's methods and creating new ones. 

68# 

69# Basic calling sequence 

70# ====================== 

71# 

72# Python's logging functionality can be conceptually divided into five steps: 

73# 0. Check logging level -> abort if call level is greater than logger level 

74# 1. Gather information -> construct a LogRecord from passed arguments and context 

75# 2. Filter (optional) -> discard message if the record matches a filter 

76# 3. Format -> format message with args, then format output string with message plus record 

77# 4. Handle -> write the formatted string to output as defined in the handler 

78# 

79# dill.logging.logger.log -> # or logger.info, etc. 

80# Logger.log -> \ 

81# Logger._log -> }- accept 'extra' parameter for custom record entries 

82# Logger.makeRecord -> / 

83# LogRecord.__init__ 

84# Logger.handle -> 

85# Logger.callHandlers -> 

86# Handler.handle -> 

87# Filterer.filter -> 

88# Filter.filter 

89# StreamHandler.emit -> 

90# Handler.format -> 

91# Formatter.format -> 

92# LogRecord.getMessage # does: record.message = msg % args 

93# Formatter.formatMessage -> 

94# PercentStyle.format # does: self._fmt % vars(record) 

95# 

96# NOTE: All methods from the second line on are from logging.__init__.py 

97 

98class TraceAdapter(logging.LoggerAdapter): 

99 """ 

100 Tracks object tree depth and calculates pickled object size. 

101 

102 A single instance of this wraps the module's logger, as the logging API 

103 doesn't allow setting it directly with a custom Logger subclass. The added 

104 'trace()' method receives a pickle instance as the first argument and 

105 creates extra values to be added in the LogRecord from it, then calls 

106 'info()'. 

107 

108 Usage of logger with 'trace()' method: 

109 

110 >>> from dill.logger import adapter as logger #NOTE: not dill.logger.logger 

111 >>> ... 

112 >>> def save_atype(pickler, obj): 

113 >>> logger.trace(pickler, "Message with %s and %r etc. placeholders", 'text', obj) 

114 >>> ... 

115 """ 

116 def __init__(self, logger): 

117 self.logger = logger 

118 def addHandler(self, handler): 

119 formatter = TraceFormatter("%(prefix)s%(message)s%(suffix)s", handler=handler) 

120 handler.setFormatter(formatter) 

121 self.logger.addHandler(handler) 

122 def removeHandler(self, handler): 

123 self.logger.removeHandler(handler) 

124 def process(self, msg, kwargs): 

125 # A no-op override, as we don't have self.extra. 

126 return msg, kwargs 

127 def trace_setup(self, pickler): 

128 # Called by Pickler.dump(). 

129 if not dill._dill.is_dill(pickler, child=False): 

130 return 

131 if self.isEnabledFor(logging.INFO): 

132 pickler._trace_depth = 1 

133 pickler._size_stack = [] 

134 else: 

135 pickler._trace_depth = None 

136 def trace(self, pickler, msg, *args, **kwargs): 

137 if not hasattr(pickler, '_trace_depth'): 

138 logger.info(msg, *args, **kwargs) 

139 return 

140 if pickler._trace_depth is None: 

141 return 

142 extra = kwargs.get('extra', {}) 

143 pushed_obj = msg.startswith('#') 

144 size = None 

145 try: 

146 # Streams are not required to be tellable. 

147 size = pickler._file.tell() 

148 frame = pickler.framer.current_frame 

149 try: 

150 size += frame.tell() 

151 except AttributeError: 

152 # PyPy may use a BytesBuilder as frame 

153 size += len(frame) 

154 except (AttributeError, TypeError): 

155 pass 

156 if size is not None: 

157 if not pushed_obj: 

158 pickler._size_stack.append(size) 

159 else: 

160 size -= pickler._size_stack.pop() 

161 extra['size'] = size 

162 if pushed_obj: 

163 pickler._trace_depth -= 1 

164 extra['depth'] = pickler._trace_depth 

165 kwargs['extra'] = extra 

166 self.info(msg, *args, **kwargs) 

167 if not pushed_obj: 

168 pickler._trace_depth += 1 

169 

170class TraceFormatter(logging.Formatter): 

171 """ 

172 Generates message prefix and suffix from record. 

173 

174 This Formatter adds prefix and suffix strings to the log message in trace 

175 mode (an also provides empty string defaults for normal logs). 

176 """ 

177 def __init__(self, *args, handler=None, **kwargs): 

178 super().__init__(*args, **kwargs) 

179 try: 

180 encoding = handler.stream.encoding 

181 if encoding is None: 

182 raise AttributeError 

183 except AttributeError: 

184 encoding = locale.getpreferredencoding() 

185 try: 

186 encoding = codecs.lookup(encoding).name 

187 except LookupError: 

188 self.is_utf8 = False 

189 else: 

190 self.is_utf8 = (encoding == codecs.lookup('utf-8').name) 

191 def format(self, record): 

192 fields = {'prefix': "", 'suffix': ""} 

193 if getattr(record, 'depth', 0) > 0: 

194 if record.msg.startswith("#"): 

195 prefix = (record.depth - 1)*"│" + "└" 

196 elif record.depth == 1: 

197 prefix = "┬" 

198 else: 

199 prefix = (record.depth - 2)*"│" + "├┬" 

200 if not self.is_utf8: 

201 prefix = prefix.translate(ASCII_MAP) + "-" 

202 fields['prefix'] = prefix + " " 

203 if hasattr(record, 'size'): 

204 # Show object size in human-redable form. 

205 power = int(math.log(record.size, 2)) // 10 

206 size = record.size >> power*10 

207 fields['suffix'] = " [%d %sB]" % (size, "KMGTP"[power] + "i" if power else "") 

208 vars(record).update(fields) 

209 return super().format(record) 

210 

211logger = logging.getLogger('dill') 

212logger.propagate = False 

213adapter = TraceAdapter(logger) 

214stderr_handler = logging._StderrHandler() 

215adapter.addHandler(stderr_handler) 

216 

217def trace(arg: Union[bool, TextIO, str, os.PathLike] = None, *, mode: str = 'a') -> None: 

218 """print a trace through the stack when pickling; useful for debugging 

219 

220 With a single boolean argument, enable or disable the tracing. 

221 

222 Example usage: 

223 

224 >>> import dill 

225 >>> dill.detect.trace(True) 

226 >>> dill.dump_session() 

227 

228 Alternatively, ``trace()`` can be used as a context manager. With no 

229 arguments, it just takes care of restoring the tracing state on exit. 

230 Either a file handle, or a file name and (optionally) a file mode may be 

231 specitfied to redirect the tracing output in the ``with`` block context. A 

232 log function is yielded by the manager so the user can write extra 

233 information to the file. 

234 

235 Example usage: 

236 

237 >>> from dill import detect 

238 >>> D = {'a': 42, 'b': {'x': None}} 

239 >>> with detect.trace(): 

240 >>> dumps(D) 

241 ┬ D2: <dict object at 0x7f2721804800> 

242 ├┬ D2: <dict object at 0x7f27217f5c40> 

243 │└ # D2 [8 B] 

244 └ # D2 [22 B] 

245 >>> squared = lambda x: x**2 

246 >>> with detect.trace('output.txt', mode='w') as log: 

247 >>> log("> D = %r", D) 

248 >>> dumps(D) 

249 >>> log("> squared = %r", squared) 

250 >>> dumps(squared) 

251 

252 Arguments: 

253 arg: a boolean value, or an optional file-like or path-like object for the context manager 

254 mode: mode string for ``open()`` if a file name is passed as the first argument 

255 """ 

256 if not isinstance(arg, bool): 

257 return TraceManager(file=arg, mode=mode) 

258 logger.setLevel(logging.INFO if arg else logging.WARNING) 

259 

260class TraceManager(contextlib.AbstractContextManager): 

261 """context manager version of trace(); can redirect the trace to a file""" 

262 def __init__(self, file, mode): 

263 self.file = file 

264 self.mode = mode 

265 self.redirect = file is not None 

266 self.file_is_stream = hasattr(file, 'write') 

267 def __enter__(self): 

268 if self.redirect: 

269 stderr_handler.flush() 

270 if self.file_is_stream: 

271 self.handler = logging.StreamHandler(self.file) 

272 else: 

273 self.handler = logging.FileHandler(self.file, self.mode) 

274 adapter.removeHandler(stderr_handler) 

275 adapter.addHandler(self.handler) 

276 self.old_level = adapter.getEffectiveLevel() 

277 adapter.setLevel(logging.INFO) 

278 return adapter.info 

279 def __exit__(self, *exc_info): 

280 adapter.setLevel(self.old_level) 

281 if self.redirect: 

282 adapter.removeHandler(self.handler) 

283 adapter.addHandler(stderr_handler) 

284 if not self.file_is_stream: 

285 self.handler.close()