debug.py 9.6 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295
  1. # Licensed under the Apache License: http://www.apache.org/licenses/LICENSE-2.0
  2. # For details: https://bitbucket.org/ned/coveragepy/src/default/NOTICE.txt
  3. """Control of and utilities for debugging."""
  4. import contextlib
  5. import inspect
  6. import os
  7. import re
  8. import sys
  9. try:
  10. import _thread
  11. except ImportError:
  12. import thread as _thread
  13. from coverage.backward import StringIO
  14. from coverage.misc import isolate_module
  15. os = isolate_module(os)
  16. # When debugging, it can be helpful to force some options, especially when
  17. # debugging the configuration mechanisms you usually use to control debugging!
  18. # This is a list of forced debugging options.
  19. FORCED_DEBUG = []
  20. # A hack for debugging testing in sub-processes.
  21. _TEST_NAME_FILE = "" # "/tmp/covtest.txt"
  22. class DebugControl(object):
  23. """Control and output for debugging."""
  24. def __init__(self, options, output):
  25. """Configure the options and output file for debugging."""
  26. self.options = list(options) + FORCED_DEBUG
  27. self.raw_output = output
  28. self.suppress_callers = False
  29. filters = []
  30. if self.should('pid'):
  31. filters.append(add_pid_and_tid)
  32. self.output = DebugOutputFile(
  33. self.raw_output,
  34. show_process=self.should('process'),
  35. filters=filters,
  36. )
  37. def __repr__(self):
  38. return "<DebugControl options=%r raw_output=%r>" % (self.options, self.raw_output)
  39. def should(self, option):
  40. """Decide whether to output debug information in category `option`."""
  41. if option == "callers" and self.suppress_callers:
  42. return False
  43. return (option in self.options)
  44. @contextlib.contextmanager
  45. def without_callers(self):
  46. """A context manager to prevent call stacks from being logged."""
  47. old = self.suppress_callers
  48. self.suppress_callers = True
  49. try:
  50. yield
  51. finally:
  52. self.suppress_callers = old
  53. def write(self, msg):
  54. """Write a line of debug output.
  55. `msg` is the line to write. A newline will be appended.
  56. """
  57. self.output.write(msg+"\n")
  58. if self.should('callers'):
  59. dump_stack_frames(out=self.output, skip=1)
  60. self.output.flush()
  61. class DebugControlString(DebugControl):
  62. """A `DebugControl` that writes to a StringIO, for testing."""
  63. def __init__(self, options):
  64. super(DebugControlString, self).__init__(options, StringIO())
  65. def get_output(self):
  66. """Get the output text from the `DebugControl`."""
  67. return self.raw_output.getvalue()
  68. def info_header(label):
  69. """Make a nice header string."""
  70. return "--{0:-<60s}".format(" "+label+" ")
  71. def info_formatter(info):
  72. """Produce a sequence of formatted lines from info.
  73. `info` is a sequence of pairs (label, data). The produced lines are
  74. nicely formatted, ready to print.
  75. """
  76. info = list(info)
  77. if not info:
  78. return
  79. label_len = max(len(l) for l, _d in info)
  80. for label, data in info:
  81. if data == []:
  82. data = "-none-"
  83. if isinstance(data, (list, set, tuple)):
  84. prefix = "%*s:" % (label_len, label)
  85. for e in data:
  86. yield "%*s %s" % (label_len+1, prefix, e)
  87. prefix = ""
  88. else:
  89. yield "%*s: %s" % (label_len, label, data)
  90. def write_formatted_info(writer, header, info):
  91. """Write a sequence of (label,data) pairs nicely."""
  92. writer.write(info_header(header))
  93. for line in info_formatter(info):
  94. writer.write(" %s" % line)
  95. def short_stack(limit=None, skip=0):
  96. """Return a string summarizing the call stack.
  97. The string is multi-line, with one line per stack frame. Each line shows
  98. the function name, the file name, and the line number:
  99. ...
  100. start_import_stop : /Users/ned/coverage/trunk/tests/coveragetest.py @95
  101. import_local_file : /Users/ned/coverage/trunk/tests/coveragetest.py @81
  102. import_local_file : /Users/ned/coverage/trunk/coverage/backward.py @159
  103. ...
  104. `limit` is the number of frames to include, defaulting to all of them.
  105. `skip` is the number of frames to skip, so that debugging functions can
  106. call this and not be included in the result.
  107. """
  108. stack = inspect.stack()[limit:skip:-1]
  109. return "\n".join("%30s : %s @%d" % (t[3], t[1], t[2]) for t in stack)
  110. def dump_stack_frames(limit=None, out=None, skip=0):
  111. """Print a summary of the stack to stdout, or someplace else."""
  112. out = out or sys.stdout
  113. out.write(short_stack(limit=limit, skip=skip+1))
  114. out.write("\n")
  115. def short_id(id64):
  116. """Given a 64-bit id, make a shorter 16-bit one."""
  117. id16 = 0
  118. for offset in range(0, 64, 16):
  119. id16 ^= id64 >> offset
  120. return id16 & 0xFFFF
  121. def add_pid_and_tid(text):
  122. """A filter to add pid and tid to debug messages."""
  123. # Thread ids are useful, but too long. Make a shorter one.
  124. tid = "{0:04x}".format(short_id(_thread.get_ident()))
  125. text = "{0:5d}.{1}: {2}".format(os.getpid(), tid, text)
  126. return text
  127. def filter_text(text, filters):
  128. """Run `text` through a series of filters.
  129. `filters` is a list of functions. Each takes a string and returns a
  130. string. Each is run in turn.
  131. Returns: the final string that results after all of the filters have
  132. run.
  133. """
  134. clean_text = text.rstrip()
  135. ending = text[len(clean_text):]
  136. text = clean_text
  137. for fn in filters:
  138. lines = []
  139. for line in text.splitlines():
  140. lines.extend(fn(line).splitlines())
  141. text = "\n".join(lines)
  142. return text + ending
  143. class CwdTracker(object): # pragma: debugging
  144. """A class to add cwd info to debug messages."""
  145. def __init__(self):
  146. self.cwd = None
  147. def filter(self, text):
  148. """Add a cwd message for each new cwd."""
  149. cwd = os.getcwd()
  150. if cwd != self.cwd:
  151. text = "cwd is now {0!r}\n".format(cwd) + text
  152. self.cwd = cwd
  153. return text
  154. class DebugOutputFile(object): # pragma: debugging
  155. """A file-like object that includes pid and cwd information."""
  156. def __init__(self, outfile, show_process, filters):
  157. self.outfile = outfile
  158. self.show_process = show_process
  159. self.filters = list(filters)
  160. if self.show_process:
  161. self.filters.append(CwdTracker().filter)
  162. cmd = " ".join(getattr(sys, 'argv', ['???']))
  163. self.write("New process: executable: %s\n" % (sys.executable,))
  164. self.write("New process: cmd: %s\n" % (cmd,))
  165. if hasattr(os, 'getppid'):
  166. self.write("New process: parent pid: %s\n" % (os.getppid(),))
  167. SYS_MOD_NAME = '$coverage.debug.DebugOutputFile.the_one'
  168. @classmethod
  169. def the_one(cls, fileobj=None, show_process=True, filters=()):
  170. """Get the process-wide singleton DebugOutputFile.
  171. If it doesn't exist yet, then create it as a wrapper around the file
  172. object `fileobj`. `show_process` controls whether the debug file adds
  173. process-level information.
  174. """
  175. # Because of the way igor.py deletes and re-imports modules,
  176. # this class can be defined more than once. But we really want
  177. # a process-wide singleton. So stash it in sys.modules instead of
  178. # on a class attribute. Yes, this is aggressively gross.
  179. the_one = sys.modules.get(cls.SYS_MOD_NAME)
  180. if the_one is None:
  181. assert fileobj is not None
  182. sys.modules[cls.SYS_MOD_NAME] = the_one = cls(fileobj, show_process, filters)
  183. return the_one
  184. def write(self, text):
  185. """Just like file.write, but filter through all our filters."""
  186. self.outfile.write(filter_text(text, self.filters))
  187. self.outfile.flush()
  188. def flush(self):
  189. """Flush our file."""
  190. self.outfile.flush()
  191. def log(msg, stack=False): # pragma: debugging
  192. """Write a log message as forcefully as possible."""
  193. out = DebugOutputFile.the_one()
  194. out.write(msg+"\n")
  195. if stack:
  196. dump_stack_frames(out=out, skip=1)
  197. def filter_aspectlib_frames(text): # pragma: debugging
  198. """Aspectlib prints stack traces, but includes its own frames. Scrub those out."""
  199. # <<< aspectlib/__init__.py:257:function_wrapper < igor.py:143:run_tests < ...
  200. text = re.sub(r"(?<= )aspectlib/[^.]+\.py:\d+:\w+ < ", "", text)
  201. return text
  202. def enable_aspectlib_maybe(): # pragma: debugging
  203. """For debugging, we can use aspectlib to trace execution.
  204. Define COVERAGE_ASPECTLIB to enable and configure aspectlib to trace
  205. execution::
  206. $ export COVERAGE_LOG=covaspect.txt
  207. $ export COVERAGE_ASPECTLIB=coverage.Coverage:coverage.data.CoverageData
  208. $ coverage run blah.py ...
  209. This will trace all the public methods on Coverage and CoverageData,
  210. writing the information to covaspect.txt.
  211. """
  212. aspects = os.environ.get("COVERAGE_ASPECTLIB", "")
  213. if not aspects:
  214. return
  215. import aspectlib # pylint: disable=import-error
  216. import aspectlib.debug # pylint: disable=import-error
  217. filename = os.environ.get("COVERAGE_LOG", "/tmp/covlog.txt")
  218. filters = [add_pid_and_tid, filter_aspectlib_frames]
  219. aspects_file = DebugOutputFile.the_one(open(filename, "a"), show_process=True, filters=filters)
  220. aspect_log = aspectlib.debug.log(
  221. print_to=aspects_file, attributes=['id'], stacktrace=30, use_logging=False
  222. )
  223. public_methods = re.compile(r'^(__init__|[a-zA-Z].*)$')
  224. for aspect in aspects.split(':'):
  225. aspectlib.weave(aspect, aspect_log, methods=public_methods)