refcounter.py 8.3 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238
  1. #!/usr/bin/env python
  2. """Process a ref debug log
  3. This file will process a log file created by the REF_DEBUG
  4. build option in Asterisk.
  5. See http://www.asterisk.org for more information about
  6. the Asterisk project. Please do not directly contact
  7. any of the maintainers of this project for assistance;
  8. the project provides a web site, mailing lists and IRC
  9. channels for your use.
  10. This program is free software, distributed under the terms of
  11. the GNU General Public License Version 2. See the LICENSE file
  12. at the top of the source tree.
  13. Copyright (C) 2014, Digium, Inc.
  14. Matt Jordan <mjordan@digium.com>
  15. """
  16. from __future__ import print_function
  17. import sys
  18. import os
  19. from optparse import OptionParser
  20. def parse_line(line):
  21. """Parse out a line into its constituent parts.
  22. Keyword Arguments:
  23. line The line from a ref debug log to parse out
  24. Returns:
  25. A dictionary containing the options, or None
  26. """
  27. tokens = line.strip().split(',', 7)
  28. if len(tokens) < 8:
  29. print("ERROR: ref debug line '%s' contains fewer tokens than "
  30. "expected: %d" % (line.strip(), len(tokens)))
  31. return None
  32. processed_line = {'addr': tokens[0],
  33. 'delta': tokens[1],
  34. 'thread_id': tokens[2],
  35. 'file': tokens[3],
  36. 'line': tokens[4],
  37. 'function': tokens[5],
  38. 'state': tokens[6],
  39. 'tag': tokens[7],
  40. }
  41. return processed_line
  42. def process_file(options):
  43. """The routine that kicks off processing a ref file
  44. Keyword Arguments:
  45. filename The full path to the file to process
  46. Returns:
  47. A tuple containing:
  48. - A list of objects whose lifetimes were completed
  49. (i.e., finished objects)
  50. - A list of objects referenced after destruction
  51. (i.e., invalid objects)
  52. - A list of objects whose lifetimes were not completed
  53. (i.e., leaked objects)
  54. - A list of objects whose lifetimes are skewed
  55. (i.e., Object history starting with an unusual ref count)
  56. """
  57. finished_objects = []
  58. invalid_objects = []
  59. leaked_objects = []
  60. skewed_objects = []
  61. current_objects = {}
  62. filename = options.filepath
  63. with open(filename, 'r') as ref_file:
  64. for line in ref_file:
  65. parsed_line = parse_line(line)
  66. if not parsed_line:
  67. continue
  68. invalid = False
  69. obj = parsed_line['addr']
  70. if obj not in current_objects:
  71. current_objects[obj] = {'log': [], 'curcount': 1}
  72. if 'constructor' in parsed_line['state']:
  73. # This is the normal expected case
  74. pass
  75. elif 'invalid' in parsed_line['state']:
  76. invalid = True
  77. current_objects[obj]['curcount'] = 0
  78. if options.invalid:
  79. invalid_objects.append((obj, current_objects[obj]))
  80. elif 'destructor' in parsed_line['state']:
  81. current_objects[obj]['curcount'] = 0
  82. if options.skewed:
  83. skewed_objects.append((obj, current_objects[obj]))
  84. else:
  85. current_objects[obj]['curcount'] = int(
  86. parsed_line['state'])
  87. if options.skewed:
  88. skewed_objects.append((obj, current_objects[obj]))
  89. else:
  90. current_objects[obj]['curcount'] += int(parsed_line['delta'])
  91. current_objects[obj]['log'].append(
  92. "[%s] %s:%s %s: %s %s - [%s]" % (
  93. parsed_line['thread_id'],
  94. parsed_line['file'],
  95. parsed_line['line'],
  96. parsed_line['function'],
  97. parsed_line['delta'],
  98. parsed_line['tag'],
  99. parsed_line['state']))
  100. # It is possible for curcount to go below zero if someone
  101. # unrefs an object by two or more when there aren't that
  102. # many refs remaining. This condition abnormally finishes
  103. # the object.
  104. if current_objects[obj]['curcount'] <= 0:
  105. if current_objects[obj]['curcount'] < 0:
  106. current_objects[obj]['log'].append(
  107. "[%s] %s:%s %s: %s %s - [%s]" % (
  108. parsed_line['thread_id'],
  109. parsed_line['file'],
  110. parsed_line['line'],
  111. parsed_line['function'],
  112. "+0",
  113. "Object abnormally finalized",
  114. "**implied destructor**"))
  115. # Highlight the abnormally finished object in the
  116. # invalid section as well as reporting it in the normal
  117. # finished section.
  118. if options.invalid:
  119. invalid_objects.append((obj, current_objects[obj]))
  120. if not invalid and options.normal:
  121. finished_objects.append((obj, current_objects[obj]))
  122. del current_objects[obj]
  123. if options.leaks:
  124. for (key, lines) in current_objects.items():
  125. leaked_objects.append((key, lines))
  126. return (finished_objects, invalid_objects, leaked_objects, skewed_objects)
  127. def print_objects(objects, prefix=""):
  128. """Prints out the objects that were processed
  129. Keyword Arguments:
  130. objects A list of objects to print
  131. prefix A prefix to print that specifies something about
  132. this object
  133. """
  134. print("======== %s Objects ========" % prefix)
  135. print("\n")
  136. for obj in objects:
  137. print("==== %s Object %s history ====" % (prefix, obj[0]))
  138. for line in obj[1]['log']:
  139. print(line)
  140. print("\n")
  141. def main(argv=None):
  142. """Main entry point for the script"""
  143. ret_code = 0
  144. if argv is None:
  145. argv = sys.argv
  146. parser = OptionParser()
  147. parser.add_option("-f", "--file", action="store", type="string",
  148. dest="filepath", default="/var/log/asterisk/refs",
  149. help="The full path to the refs file to process")
  150. parser.add_option("-i", "--suppress-invalid", action="store_false",
  151. dest="invalid", default=True,
  152. help="If specified, don't output invalid object "
  153. "references")
  154. parser.add_option("-l", "--suppress-leaks", action="store_false",
  155. dest="leaks", default=True,
  156. help="If specified, don't output leaked objects")
  157. parser.add_option("-n", "--suppress-normal", action="store_false",
  158. dest="normal", default=True,
  159. help="If specified, don't output objects with a "
  160. "complete lifetime")
  161. parser.add_option("-s", "--suppress-skewed", action="store_false",
  162. dest="skewed", default=True,
  163. help="If specified, don't output objects with a "
  164. "skewed lifetime")
  165. (options, args) = parser.parse_args(argv)
  166. if not options.invalid and not options.leaks and not options.normal \
  167. and not options.skewed:
  168. print("All options disabled", file=sys.stderr)
  169. return -1
  170. if not os.path.isfile(options.filepath):
  171. print("File not found: %s" % options.filepath, file=sys.stderr)
  172. return -1
  173. try:
  174. (finished_objects,
  175. invalid_objects,
  176. leaked_objects,
  177. skewed_objects) = process_file(options)
  178. if options.invalid and len(invalid_objects):
  179. print_objects(invalid_objects, "Invalid Referenced")
  180. ret_code |= 4
  181. if options.leaks and len(leaked_objects):
  182. print_objects(leaked_objects, "Leaked")
  183. ret_code |= 1
  184. if options.skewed and len(skewed_objects):
  185. print_objects(skewed_objects, "Skewed")
  186. ret_code |= 2
  187. if options.normal:
  188. print_objects(finished_objects, "Finalized")
  189. except (KeyboardInterrupt, SystemExit, IOError):
  190. print("File processing cancelled", file=sys.stderr)
  191. return -1
  192. return ret_code
  193. if __name__ == "__main__":
  194. sys.exit(main(sys.argv))