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