1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18 r"""replaylog.py: Log all xapian calls to a file, so that they can be replayed.
19
20 """
21 __docformat__ = "restructuredtext en"
22
23 import datetime
24 import sys
25 import thread
26 import threading
27 import time
28 import traceback
29 import types
30 import weakref
31 import xapian
32
33 from pprint import pprint
34
35
36 _replay_log = None
37
38
39 _had_replay_log = False
40
42 """An wrapping for an object which calls a callback when its deleted.
43
44 Note that the callback will be called from a __del__ method, so shouldn't
45 raise any exceptions, and probably shouldn't make new references to the
46 object supplied to it.
47
48 """
50 self.obj = obj
51 self.callback = callback
52
54 self.callback(self.obj)
55
57 """Log of xapian calls, to be replayed.
58
59 """
60
62 """Create a new replay log.
63
64 """
65
66 self._fd_mutex = threading.Lock()
67 self._fd = file(logpath, 'wb')
68
69
70 self._mutex = threading.Lock()
71 self._next_call = 1
72
73 self._next_thread = 0
74 self._thread_ids = {}
75
76 self._objs = weakref.WeakKeyDictionary()
77 self._next_num = 1
78
79 self._xapian_classes = {}
80 self._xapian_functions = {}
81 self._xapian_methods = {}
82 for name in dir(xapian):
83 item = getattr(xapian, name)
84 has_members = False
85 for membername in dir(item):
86 member = getattr(item, membername)
87 if isinstance(member, types.MethodType):
88 self._xapian_methods[member.im_func] = (name, membername)
89 has_members = True
90 if has_members:
91 self._xapian_classes[item] = name
92 if isinstance(item, types.BuiltinFunctionType):
93 self._xapian_functions[item] = name
94
96 """Get the number associated with an object.
97
98 If maybe_new is False, a value of 0 will be supplied if the object
99 hasn't already been seen. Otherwise, a new (and previously unused)
100 value will be allocated to the object.
101
102 The mutex should be held when this is called.
103
104 """
105 try:
106 num = self._objs[obj]
107 return num.obj
108 except KeyError:
109 pass
110
111 if not maybe_new:
112 return 0
113
114 self._objs[obj] = NotifyingDeleteObject(self._next_num, self._obj_gone)
115 self._next_num += 1
116 return self._next_num - 1
117
119 """Return True iff an object is an instance of a xapian object.
120
121 (Also returns true if the object is an instance of a subclass of a
122 xapian object.)
123
124 The mutex should be held when this is called.
125
126 """
127
128 classname = self._xapian_classes.get(type(obj), None)
129 if classname is not None:
130 return True
131
132 for classobj, classname in self._xapian_classes.iteritems():
133 if isinstance(obj, classobj):
134 return True
135
136 return False
137
139 """Get the name of a xapian class or method.
140
141 The mutex should be held when this is called.
142
143 """
144
145 if isinstance(obj, types.TypeType):
146 classname = self._xapian_classes.get(obj, None)
147 if classname is not None:
148 return classname
149
150 for classobj, classname in self._xapian_classes.iteritems():
151 if issubclass(obj, classobj):
152 return "subclassof_%s" % (classname, )
153
154 return None
155
156
157 if isinstance(obj, types.BuiltinFunctionType):
158 funcname = self._xapian_functions.get(obj, None)
159 if funcname is not None:
160 return funcname
161
162
163 if isinstance(obj, LoggedProxy):
164 classname = self._xapian_classes.get(obj.__class__, None)
165 if classname is not None:
166 objnum = self._get_obj_num(obj, maybe_new=maybe_new)
167 return "%s#%d" % (classname, objnum)
168
169
170 if isinstance(obj, LoggedProxyMethod):
171 classname, methodname = self._xapian_methods[obj.real.im_func]
172 objnum = self._get_obj_num(obj.proxyobj, maybe_new=maybe_new)
173 return "%s#%d.%s" % (classname, objnum, methodname)
174
175
176
177
178 for classobj, classname in self._xapian_classes.iteritems():
179 if isinstance(obj, classobj):
180 objnum = self._get_obj_num(obj, maybe_new=maybe_new)
181 return "subclassof_%s#%d" % (classname, objnum)
182
183 return None
184
185 - def _log(self, msg):
186 self._fd_mutex.acquire()
187 try:
188
189
190
191
192 self._fd.write(msg)
193 self._fd.flush()
194 finally:
195 self._fd_mutex.release()
196
198 """Return a representation of an argument.
199
200 The mutex should be held when this is called.
201
202 """
203
204 xapargname = self._get_xap_name(arg)
205 if xapargname is not None:
206 return xapargname
207
208 if isinstance(arg, basestring):
209 if isinstance(arg, unicode):
210 arg = arg.encode('utf-8')
211 return 'str(%d,%s)' % (len(arg), arg)
212
213 if isinstance(arg, long):
214 try:
215 arg = int(arg)
216 except OverFlowError:
217 pass
218
219 if isinstance(arg, long):
220 return 'long(%d)' % arg
221
222 if isinstance(arg, int):
223 return 'int(%d)' % arg
224
225 if isinstance(arg, float):
226 return 'float(%f)' % arg
227
228 if arg is None:
229 return 'None'
230
231 if hasattr(arg, '__iter__'):
232 seq = []
233 for item in arg:
234 seq.append(self._repr_arg(item))
235 return 'list(%s)' % ','.join(seq)
236
237 return 'UNKNOWN:' + str(arg)
238
240 """Return a representation of a list of arguments.
241
242 The mutex should be held when this is called.
243
244 """
245 logargs = []
246 for arg in args:
247 logargs.append(self._repr_arg(arg))
248 return ','.join(logargs)
249
251 """Get an ID string for a call.
252
253 The mutex should be held when this is called.
254
255 """
256 call_num = self._next_call
257 self._next_call += 1
258
259 thread_id = thread.get_ident()
260 try:
261 thread_num = self._thread_ids[thread_id]
262 except KeyError:
263 thread_num = self._next_thread
264 self._thread_ids[thread_id] = thread_num
265 self._next_thread += 1
266
267 if thread_num is 0:
268 return "%s" % call_num
269 return "%dT%d" % (call_num, thread_num)
270
272 """Add a log message about a call.
273
274 Returns a number for the call, so it can be tied to a particular
275 result.
276
277 """
278 self._mutex.acquire()
279 try:
280 logargs = self._repr_args(args)
281 xapobjname = self._get_xap_name(call)
282 call_id = self._get_call_id()
283 finally:
284 self._mutex.release()
285
286 if xapobjname is not None:
287 self._log("CALL%s:%s(%s)\n" % (call_id, xapobjname, logargs))
288 else:
289 self._log("CALL%s:UNKNOWN:%r(%s)\n" % (call_id, call, logargs))
290 return call_id
291
292 - def log_except(self, (etype, value, tb), call_id):
293 """Log an exception which has occurred.
294
295 """
296
297 exc = traceback.format_exception_only(etype, value)
298 self._log("EXCEPT%s:%s\n" % (call_id, ''.join(exc).strip()))
299
301 """Log a return value.
302
303 """
304 if ret is None:
305 self._log("RET%s:None\n" % call_id)
306 return
307
308 self._mutex.acquire()
309 try:
310
311 if self._is_xap_obj(ret):
312 ret = LoggedProxy(ret)
313 xapobjname = self._get_xap_name(ret, maybe_new=True)
314 msg = "RET%s:%s\n" % (call_id, self._repr_arg(ret))
315 finally:
316 self._mutex.release()
317
318
319 self._log(msg)
320 return ret
321
323 """Log that an object has been deleted.
324
325 """
326 self._log('DEL:#%d\n' % num)
327
329 """A proxy for a xapian object, which logs all calls made on the object.
330
331 """
334
336 obj = object.__getattribute__(self, '_LoggedProxy__obj')
337 if name == '__obj':
338 return obj
339 real = getattr(obj, name)
340 if not isinstance(real, types.MethodType):
341 return real
342 return LoggedProxyMethod(real, self)
343
347
351
355
359
361 """A proxy for a xapian method, which logs all calls made on the method.
362
363 """
365 """Make a proxy for the method.
366
367 """
368 self.real = real
369 self.proxyobj = proxyobj
370
372 """Call the proxied method, logging the call.
373
374 """
375 return log(self, *args)
376
388
390 """Convert a call and list of arguments to unproxied form.
391
392 """
393 if isinstance(call, LoggedProxyMethod):
394 realcall = call.real
395 else:
396 realcall = call
397
398 realargs = []
399 for arg in args:
400 if isinstance(arg, LoggedProxy):
401 arg = arg.__obj
402 realargs.append(arg)
403
404 return realcall, realargs
405
406 -def log(call, *args):
407 """Make a call to xapian, and log it.
408
409 """
410
411 global _had_replay_log
412 if not _had_replay_log:
413 return call(*args)
414
415
416 realcall, realargs = _unproxy_call_and_args(call, args)
417
418
419 global _replay_log
420 replay_log = _replay_log
421 if replay_log is None:
422 return realcall(*realargs)
423
424
425 call_id = replay_log.log_call(call, *args)
426 try:
427 ret = realcall(*realargs)
428 except:
429 replay_log.log_except(sys.exc_info(), call_id)
430 raise
431 return replay_log.log_retval(ret, call_id)
432
433
434