Merge lp:~stefanor/ibid/memory-logging into lp:~ibid-core/ibid/old-trunk-pack-0.92

Proposed by Stefano Rivera
Status: Merged
Approved by: Stefano Rivera
Approved revision: 681
Merged at revision: 678
Proposed branch: lp:~stefanor/ibid/memory-logging
Merge into: lp:~ibid-core/ibid/old-trunk-pack-0.92
Diff against target: None lines
To merge this branch: bzr merge lp:~stefanor/ibid/memory-logging
Reviewer Review Type Date Requested Status
Jonathan Hitchcock Approve
Michael Gorven Approve
Review via email: mp+7974@code.launchpad.net
To post a comment you must log in.
Revision history for this message
Stefano Rivera (stefanor) wrote :

Some of this may not be useful. Do we want this kind of thing in mainline?

lp:~stefanor/ibid/memory-logging updated
680. By Stefano Rivera

Don't overlap dates in memgraph

681. By Stefano Rivera

Disable logging by default

Revision history for this message
Michael Gorven (mgorven) wrote :

I would have tried to use Python logging's rotating logfiles instead of doing
it manually, but since you've already implemented this it's fine. I think
that the logging processor should have autoload=False though, so that it has
to be explicitly enabled.
 review approve

review: Approve
Revision history for this message
Jonathan Hitchcock (vhata) wrote :

Not sure if we do want it in the main line of code. Let's put it in now, and factor it out into devtools-plugins when we finally get round to refactoring.

review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
=== added file 'ibid/plugins/memory.py'
--- ibid/plugins/memory.py 1970-01-01 00:00:00 +0000
+++ ibid/plugins/memory.py 2009-06-27 22:50:48 +0000
@@ -0,0 +1,104 @@
1import csv
2from datetime import datetime, timedelta
3import gc
4import gzip
5import os
6import os.path
7
8import simplejson
9import objgraph
10
11import ibid
12from ibid.plugins import Processor, match
13from ibid.config import Option, IntOption
14
15help = {}
16
17help['memory'] = u'Debugging module that keeps track of memory usage'
18
19def get_memusage():
20 status = file('/proc/%i/status' % os.getpid(), 'r').readlines()
21 status = [x.strip().split(':', 1) for x in status if x.startswith('Vm')]
22 return dict((x, int(y.split()[0])) for (x, y) in status)
23
24class MemoryLog(Processor):
25
26 feature = 'memory'
27
28 mem_filename = Option('mem_filename', 'Memory log filename', 'logs/memory.log')
29 mem_interval = IntOption('mem_interval', 'Interval between memory stat logging', 1)
30 obj_filename = Option('obj_filename', 'Object Statistics log filename', 'logs/objstats.log')
31 obj_interval = IntOption('obj_interval', 'Interval between logging object statistics', 1)
32
33 def setup(self):
34 fns = []
35 if self.mem_interval:
36 fns.append(self.mem_filename)
37 if self.obj_interval:
38 fns.append(self.obj_filename)
39 for filename in fns:
40 if os.path.isfile(filename + '.10.gz'):
41 os.remove(filename + '.10.gz')
42 for i in range(9, 0, -1):
43 if os.path.isfile('%s.%i.gz' % (filename, i)):
44 os.rename('%s.%i.gz' % (filename, i),
45 '%s.%i.gz' % (filename, i+1))
46 if os.path.isfile(filename):
47 o = gzip.open(filename + '.1.gz', 'wb')
48 i = open(filename, 'rb')
49 o.write(i.read())
50 o.close()
51 i.close()
52 stat = os.stat(filename)
53 os.utime(filename + '.1.gz', (stat.st_atime, stat.st_mtime))
54
55 if self.mem_interval:
56 self.mem_file = file(self.mem_filename, 'w+')
57 self.mem_file.write('Ibid Memory Log v2: %s\n' % ibid.config['botname'])
58 self.mem_csv = csv.writer(self.mem_file)
59 self.mem_last = datetime.utcnow()
60
61 if self.obj_interval:
62 self.obj_file = file(self.obj_filename, 'w+')
63 self.obj_file.write('Ibid Object Log v1: %s\n' % ibid.config['botname'])
64 self.obj_last = datetime.utcnow()
65
66 def process(self, event):
67 now = datetime.utcnow()
68 if self.mem_interval and now - self.mem_last >= timedelta(seconds=self.mem_interval):
69 self.mem_log()
70 self.mem_last = now
71 if self.obj_interval and now - self.obj_last >= timedelta(seconds=self.obj_interval):
72 self.obj_log()
73 self.obj_last = now
74
75 def mem_log(self):
76 status = get_memusage()
77 gc.collect()
78
79 self.mem_csv.writerow((
80 datetime.utcnow().isoformat(),
81 len(gc.get_objects()),
82 status['VmSize'],
83 status['VmRSS'],
84 ))
85 self.mem_file.flush()
86
87 def obj_log(self):
88 stats = objgraph.typestats()
89 self.obj_file.write('%s %s\n' % (
90 datetime.utcnow().isoformat(),
91 simplejson.dumps(objgraph.typestats())
92 ))
93 self.obj_file.flush()
94
95class MemoryInfo(Processor):
96 u"memory usage"
97
98 feature = 'memory'
99
100 @match('^memory\s+usage$')
101 def memory_usage(self, event):
102 event.addresponse(u"Today, I weigh in at %(VmSize)i kiB Virtual, %(VmRSS)s kiB RSS", get_memusage())
103
104# vi: set et sta sw=4 ts=4:
0105
=== added file 'lib/objgraph.py'
--- lib/objgraph.py 1970-01-01 00:00:00 +0000
+++ lib/objgraph.py 2009-06-27 22:50:48 +0000
@@ -0,0 +1,416 @@
1"""
2Ad-hoc tools for drawing Python object reference graphs with graphviz.
3
4This module is more useful as a repository of sample code and ideas, than
5as a finished product. For documentation and background, read
6
7 http://mg.pov.lt/blog/hunting-python-memleaks.html
8 http://mg.pov.lt/blog/python-object-graphs.html
9 http://mg.pov.lt/blog/object-graphs-with-graphviz.html
10
11in that order. Then use pydoc to read the docstrings, as there were
12improvements made since those blog posts.
13
14Copyright (c) 2008 Marius Gedminas <marius@pov.lt>
15
16Released under the MIT licence.
17
18
19Changes
20=======
21
22(unreleased)
23------------
24
25Highlight objects with a __del__ method.
26
27
281.2 (2009-03-25)
29----------------
30
31Project website, public source repository, uploaded to PyPI.
32
33No code changes.
34
35
361.1dev (2008-09-05)
37-------------------
38
39New function: show_refs() for showing forward references.
40
41New functions: typestats() and show_most_common_types().
42
43Object boxes are less crammed with useless information (such as IDs).
44
45Spawns xdot if it is available.
46"""
47# Permission is hereby granted, free of charge, to any person obtaining a
48# copy of this software and associated documentation files (the "Software"),
49# to deal in the Software without restriction, including without limitation
50# the rights to use, copy, modify, merge, publish, distribute, sublicense,
51# and/or sell copies of the Software, and to permit persons to whom the
52# Software is furnished to do so, subject to the following conditions:
53#
54# The above copyright notice and this permission notice shall be included in
55# all copies or substantial portions of the Software.
56#
57# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
58# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
59# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
60# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
61# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
62# FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER
63# DEALINGS IN THE SOFTWARE.
64
65__author__ = "Marius Gedminas (marius@gedmin.as)"
66__copyright__ = "Copyright (c) 2008, 2009 Marius Gedminas"
67__license__ = "MIT"
68__version__ = "1.2+bzr"
69__date__ = "2009-03-25"
70
71
72import gc
73import inspect
74import types
75import weakref
76import operator
77import os
78
79
80def count(typename):
81 """Count objects tracked by the garbage collector with a given class name.
82
83 Example:
84
85 >>> count('dict')
86 42
87 >>> count('MyClass')
88 3
89
90 Note that the GC does not track simple objects like int or str.
91 """
92 return sum(1 for o in gc.get_objects() if type(o).__name__ == typename)
93
94
95def typestats():
96 """Count the number of instances for each type tracked by the GC.
97
98 Note that the GC does not track simple objects like int or str.
99
100 Note that classes with the same name but defined in different modules
101 will be lumped together.
102 """
103 stats = {}
104 for o in gc.get_objects():
105 stats.setdefault(type(o).__name__, 0)
106 stats[type(o).__name__] += 1
107 return stats
108
109
110def show_most_common_types(limit=10):
111 """Count the names of types with the most instances.
112
113 Note that the GC does not track simple objects like int or str.
114
115 Note that classes with the same name but defined in different modules
116 will be lumped together.
117 """
118 stats = sorted(typestats().items(), key=operator.itemgetter(1),
119 reverse=True)
120 if limit:
121 stats = stats[:limit]
122 width = max(len(name) for name, count in stats)
123 for name, count in stats[:limit]:
124 print name.ljust(width), count
125
126
127def by_type(typename):
128 """Return objects tracked by the garbage collector with a given class name.
129
130 Example:
131
132 >>> by_type('MyClass')
133 [<mymodule.MyClass object at 0x...>]
134
135 Note that the GC does not track simple objects like int or str.
136 """
137 return [o for o in gc.get_objects() if type(o).__name__ == typename]
138
139
140def at(addr):
141 """Return an object at a given memory address.
142
143 The reverse of id(obj):
144
145 >>> at(id(obj)) is obj
146 True
147
148 Note that this function does not work on objects that are not tracked by
149 the GC (e.g. ints or strings).
150 """
151 for o in gc.get_objects():
152 if id(o) == addr:
153 return o
154 return None
155
156
157def find_backref_chain(obj, predicate, max_depth=20, extra_ignore=()):
158 """Find a shortest chain of references leading to obj.
159
160 The start of the chain will be some object that matches your predicate.
161
162 ``max_depth`` limits the search depth.
163
164 ``extra_ignore`` can be a list of object IDs to exclude those objects from
165 your search.
166
167 Example:
168
169 >>> find_backref_chain(obj, inspect.ismodule)
170 [<module ...>, ..., obj]
171
172 Returns None if such a chain could not be found.
173 """
174 queue = [obj]
175 depth = {id(obj): 0}
176 parent = {id(obj): None}
177 ignore = set(extra_ignore)
178 ignore.add(id(extra_ignore))
179 ignore.add(id(queue))
180 ignore.add(id(depth))
181 ignore.add(id(parent))
182 ignore.add(id(ignore))
183 gc.collect()
184 while queue:
185 target = queue.pop(0)
186 if predicate(target):
187 chain = [target]
188 while parent[id(target)] is not None:
189 target = parent[id(target)]
190 chain.append(target)
191 return chain
192 tdepth = depth[id(target)]
193 if tdepth < max_depth:
194 referrers = gc.get_referrers(target)
195 ignore.add(id(referrers))
196 for source in referrers:
197 if inspect.isframe(source) or id(source) in ignore:
198 continue
199 if id(source) not in depth:
200 depth[id(source)] = tdepth + 1
201 parent[id(source)] = target
202 queue.append(source)
203 return None # not found
204
205
206def show_backrefs(objs, max_depth=3, extra_ignore=(), filter=None, too_many=10,
207 highlight=None):
208 """Generate an object reference graph ending at ``objs``
209
210 The graph will show you what objects refer to ``objs``, directly and
211 indirectly.
212
213 ``objs`` can be a single object, or it can be a list of objects.
214
215 Produces a Graphviz .dot file and spawns a viewer (xdot) if one is
216 installed, otherwise converts the graph to a .png image.
217
218 Use ``max_depth`` and ``too_many`` to limit the depth and breadth of the
219 graph.
220
221 Use ``filter`` (a predicate) and ``extra_ignore`` (a list of object IDs) to
222 remove undesired objects from the graph.
223
224 Use ``highlight`` (a predicate) to highlight certain graph nodes in blue.
225
226 Examples:
227
228 >>> show_backrefs(obj)
229 >>> show_backrefs([obj1, obj2])
230 >>> show_backrefs(obj, max_depth=5)
231 >>> show_backrefs(obj, filter=lambda x: not inspect.isclass(x))
232 >>> show_backrefs(obj, highlight=inspect.isclass)
233 >>> show_backrefs(obj, extra_ignore=[id(locals())])
234
235 """
236 show_graph(objs, max_depth=max_depth, extra_ignore=extra_ignore,
237 filter=filter, too_many=too_many, highlight=highlight,
238 edge_func=gc.get_referrers, swap_source_target=False)
239
240
241def show_refs(objs, max_depth=3, extra_ignore=(), filter=None, too_many=10,
242 highlight=None):
243 """Generate an object reference graph starting at ``objs``
244
245 The graph will show you what objects are reachable from ``objs``, directly
246 and indirectly.
247
248 ``objs`` can be a single object, or it can be a list of objects.
249
250 Produces a Graphviz .dot file and spawns a viewer (xdot) if one is
251 installed, otherwise converts the graph to a .png image.
252
253 Use ``max_depth`` and ``too_many`` to limit the depth and breadth of the
254 graph.
255
256 Use ``filter`` (a predicate) and ``extra_ignore`` (a list of object IDs) to
257 remove undesired objects from the graph.
258
259 Use ``highlight`` (a predicate) to highlight certain graph nodes in blue.
260
261 Examples:
262
263 >>> show_refs(obj)
264 >>> show_refs([obj1, obj2])
265 >>> show_refs(obj, max_depth=5)
266 >>> show_refs(obj, filter=lambda x: not inspect.isclass(x))
267 >>> show_refs(obj, highlight=inspect.isclass)
268 >>> show_refs(obj, extra_ignore=[id(locals())])
269
270 """
271 show_graph(objs, max_depth=max_depth, extra_ignore=extra_ignore,
272 filter=filter, too_many=too_many, highlight=highlight,
273 edge_func=gc.get_referents, swap_source_target=True)
274
275#
276# Internal helpers
277#
278
279def show_graph(objs, edge_func, swap_source_target,
280 max_depth=3, extra_ignore=(), filter=None, too_many=10,
281 highlight=None):
282 if not isinstance(objs, (list, tuple)):
283 objs = [objs]
284 f = file('objects.dot', 'w')
285 print >> f, 'digraph ObjectGraph {'
286 print >> f, ' node[shape=box, style=filled, fillcolor=white];'
287 queue = []
288 depth = {}
289 ignore = set(extra_ignore)
290 ignore.add(id(objs))
291 ignore.add(id(extra_ignore))
292 ignore.add(id(queue))
293 ignore.add(id(depth))
294 ignore.add(id(ignore))
295 for obj in objs:
296 print >> f, ' %s[fontcolor=red];' % (obj_node_id(obj))
297 depth[id(obj)] = 0
298 queue.append(obj)
299 gc.collect()
300 nodes = 0
301 while queue:
302 nodes += 1
303 target = queue.pop(0)
304 tdepth = depth[id(target)]
305 print >> f, ' %s[label="%s"];' % (obj_node_id(target), obj_label(target, tdepth))
306 h, s, v = gradient((0, 0, 1), (0, 0, .3), tdepth, max_depth)
307 if inspect.ismodule(target):
308 h = .3
309 s = 1
310 if highlight and highlight(target):
311 h = .6
312 s = .6
313 v = 0.5 + v * 0.5
314 print >> f, ' %s[fillcolor="%g,%g,%g"];' % (obj_node_id(target), h, s, v)
315 if v < 0.5:
316 print >> f, ' %s[fontcolor=white];' % (obj_node_id(target))
317 if hasattr(target, '__del__'):
318 print >> f, " %s->%s_has_a_del[color=red,style=dotted,len=0.25,weight=10];" % (obj_node_id(target), obj_node_id(target))
319 print >> f, ' %s_has_a_del[label="__del__",shape=doublecircle,height=0.25,color=red,fillcolor="0,.5,1",fontsize=6];' % (obj_node_id(target))
320 if inspect.ismodule(target) or tdepth >= max_depth:
321 continue
322 neighbours = edge_func(target)
323 ignore.add(id(neighbours))
324 n = 0
325 for source in neighbours:
326 if inspect.isframe(source) or id(source) in ignore:
327 continue
328 if filter and not filter(source):
329 continue
330 if swap_source_target:
331 srcnode, tgtnode = target, source
332 else:
333 srcnode, tgtnode = source, target
334 elabel = edge_label(srcnode, tgtnode)
335 print >> f, ' %s -> %s%s;' % (obj_node_id(srcnode), obj_node_id(tgtnode), elabel)
336 if id(source) not in depth:
337 depth[id(source)] = tdepth + 1
338 queue.append(source)
339 n += 1
340 if n >= too_many:
341 print >> f, ' %s[color=red];' % obj_node_id(target)
342 break
343 print >> f, "}"
344 f.close()
345 print "Graph written to objects.dot (%d nodes)" % nodes
346 if os.system('which xdot >/dev/null') == 0:
347 print "Spawning graph viewer (xdot)"
348 os.system("xdot objects.dot &")
349 else:
350 os.system("dot -Tpng objects.dot > objects.png")
351 print "Image generated as objects.png"
352
353
354def obj_node_id(obj):
355 if isinstance(obj, weakref.ref):
356 return 'all_weakrefs_are_one'
357 return ('o%d' % id(obj)).replace('-', '_')
358
359
360def obj_label(obj, depth):
361 return quote(type(obj).__name__ + ':\n' +
362 safe_repr(obj))
363
364
365def quote(s):
366 return s.replace("\\", "\\\\").replace("\"", "\\\"").replace("\n", "\\n")
367
368
369def safe_repr(obj):
370 try:
371 return short_repr(obj)
372 except:
373 return '(unrepresentable)'
374
375
376def short_repr(obj):
377 if isinstance(obj, (type, types.ModuleType, types.BuiltinMethodType,
378 types.BuiltinFunctionType)):
379 return obj.__name__
380 if isinstance(obj, types.MethodType):
381 if obj.im_self is not None:
382 return obj.im_func.__name__ + ' (bound)'
383 else:
384 return obj.im_func.__name__
385 if isinstance(obj, (tuple, list, dict, set)):
386 return '%d items' % len(obj)
387 if isinstance(obj, weakref.ref):
388 return 'all_weakrefs_are_one'
389 return repr(obj)[:40]
390
391
392def gradient(start_color, end_color, depth, max_depth):
393 if max_depth == 0:
394 # avoid division by zero
395 return start_color
396 h1, s1, v1 = start_color
397 h2, s2, v2 = end_color
398 f = float(depth) / max_depth
399 h = h1 * (1-f) + h2 * f
400 s = s1 * (1-f) + s2 * f
401 v = v1 * (1-f) + v2 * f
402 return h, s, v
403
404
405def edge_label(source, target):
406 if isinstance(target, dict) and target is getattr(source, '__dict__', None):
407 return ' [label="__dict__",weight=10]'
408 elif isinstance(source, dict):
409 for k, v in source.iteritems():
410 if v is target:
411 if isinstance(k, basestring) and k:
412 return ' [label="%s",weight=2]' % quote(k)
413 else:
414 return ' [label="%s"]' % quote(safe_repr(k))
415 return ''
416
0417
=== added file 'scripts/ibid-memgraph'
--- scripts/ibid-memgraph 1970-01-01 00:00:00 +0000
+++ scripts/ibid-memgraph 2009-06-27 22:50:48 +0000
@@ -0,0 +1,68 @@
1#!/usr/bin/env python
2
3import gzip
4import optparse
5import sys
6
7import dateutil
8import matplotlib.pyplot as pyplot
9from matplotlib.dates import date2num
10import numpy
11
12parser = optparse.OptionParser(usage="""%prog logfile
13logfile is a memory log file (possibly gzipped)""")
14parser.add_option('-o', '--output', dest='output', metavar='FILE',
15 help='Output to filename rather than interactive')
16parser.add_option('-d', '--dpi', dest='dpi',
17 help='Output DPI')
18
19(options, args) = parser.parse_args()
20
21if len(args) != 1:
22 sys.stderr.write("Log file required\n")
23 sys.exit(2)
24
25f = args[0].endswith('.gz') and gzip.GzipFile(args[0], 'r') or file(args[0], 'r')
26header = f.readline().strip()
27f.close()
28if not header.startswith('Ibid Memory Log v2: '):
29 sys.stderr.write("Incorrect file format\n")
30 sys.exit(1)
31
32botname = header.split(':', 1)[1].strip()
33
34data = numpy.loadtxt(args[0],
35 dtype=float,
36 delimiter=',',
37 skiprows=1,
38 converters={0: lambda x: date2num(dateutil.parser.parse(x))},
39)
40
41fig = pyplot.figure()
42ax_obj = fig.add_subplot(111)
43ax_obj.set_xlabel('time (s)')
44ax_mem = ax_obj.twinx()
45ax_mem.grid(True)
46
47ax_obj.plot_date(data[:,0], data[:,1]/1000, 'b-', label='Objects (k)')
48ax_obj.set_ylabel('Objects (k)', color='b')
49
50for tl in ax_obj.get_yticklabels():
51 tl.set_color('b')
52
53ax_mem.plot_date(data[:,0], data[:,2]/1024, 'r-', label='VM Size')
54ax_mem.plot_date(data[:,0], data[:,3]/1024, 'g-', label='VM RSS')
55
56ax_mem.set_ylabel('Memory (MiB)')
57
58pyplot.legend(loc='best')
59pyplot.title(botname + ' Memory Usage')
60
61fig.autofmt_xdate()
62
63if options.output:
64 pyplot.savefig(options.output, dpi=options.dpi)
65else:
66 pyplot.show()
67
68# vi: set et sta sw=4 ts=4:
069
=== added file 'scripts/ibid-objgraph'
--- scripts/ibid-objgraph 1970-01-01 00:00:00 +0000
+++ scripts/ibid-objgraph 2009-06-27 22:50:48 +0000
@@ -0,0 +1,77 @@
1#!/usr/bin/env python
2
3import gzip
4import optparse
5import sys
6
7import dateutil
8import simplejson
9
10import matplotlib.pyplot as pyplot
11from matplotlib.dates import date2num
12import numpy
13
14parser = optparse.OptionParser(usage="""%prog [arguments] logfile types...
15logfile is an object log file (possibly gzipped)
16types are a list of object types to graph""")
17parser.add_option('-o', '--output', dest='output', metavar='FILE',
18 help='Output to filename rather than interactive')
19parser.add_option('-d', '--dpi', dest='dpi',
20 help='Output DPI')
21
22(options, args) = parser.parse_args()
23
24if len(args) < 1:
25 sys.stderr.write("Log file required\n")
26 sys.exit(2)
27if len(args) < 2:
28 sys.stderr.write("At least one type required\n")
29 sys.exit(2)
30
31f = args[0].endswith('.gz') and gzip.GzipFile(args[0], 'r') or file(args[0], 'r')
32header = f.readline().strip()
33
34if not header.startswith('Ibid Object Log v1: '):
35 sys.stderr.write("Incorrect file format\n")
36 sys.exit(1)
37
38botname = header.split(':', 1)[1].strip()
39
40types = args[1:]
41
42times = []
43data = []
44
45for line in f:
46 timestamp, json = line.split(' ', 1)
47
48 times.append(date2num(dateutil.parser.parse(timestamp)))
49
50 json = simplejson.loads(json)
51 data.append([json.get(type, 0) for type in types])
52
53times = numpy.array(times, dtype=float)
54data = numpy.array(data, dtype=int)
55
56fig = pyplot.figure()
57ax = fig.add_subplot(111)
58ax.set_xlabel('time (s)')
59ax.set_ylabel('Objects (k)', color='b')
60ax.grid(True)
61
62ax.set_color_cycle(list('brgycmk'))
63
64for i, type in enumerate(types):
65 ax.plot_date(times, data[:,i], '-', label=type)
66
67pyplot.legend(loc='best')
68pyplot.title(botname + ' Object Stats')
69
70fig.autofmt_xdate()
71
72if options.output:
73 pyplot.savefig(options.output, dpi=options.dpi)
74else:
75 pyplot.show()
76
77# vi: set et sta sw=4 ts=4:

Subscribers

People subscribed via source and target branches