Package xappy :: Module replaylog
[frames] | no frames]

Source Code for Module xappy.replaylog

  1  #!/usr/bin/env python 
  2  # 
  3  # Copyright (C) 2007 Lemur Consulting Ltd 
  4  # 
  5  # This program is free software; you can redistribute it and/or modify 
  6  # it under the terms of the GNU General Public License as published by 
  7  # the Free Software Foundation; either version 2 of the License, or 
  8  # (at your option) any later version. 
  9  # 
 10  # This program is distributed in the hope that it will be useful, 
 11  # but WITHOUT ANY WARRANTY; without even the implied warranty of 
 12  # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the 
 13  # GNU General Public License for more details. 
 14  #  
 15  # You should have received a copy of the GNU General Public License along 
 16  # with this program; if not, write to the Free Software Foundation, Inc., 
 17  # 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. 
 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  # The logger in use. 
 36  _replay_log = None 
 37   
 38  # True if a replay log has ever been in use since import time. 
 39  _had_replay_log = False 
 40   
41 -class NotifyingDeleteObject(object):
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 """
49 - def __init__(self, obj, callback):
50 self.obj = obj 51 self.callback = callback
52
53 - def __del__(self):
54 self.callback(self.obj)
55
56 -class ReplayLog(object):
57 """Log of xapian calls, to be replayed. 58 59 """ 60
61 - def __init__(self, logpath):
62 """Create a new replay log. 63 64 """ 65 # Mutex used to protect all access to _fd 66 self._fd_mutex = threading.Lock() 67 self._fd = file(logpath, 'wb') 68 69 # Mutex used to protect all access to members other than _fd 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
95 - def _get_obj_num(self, obj, maybe_new):
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
118 - def _is_xap_obj(self, obj):
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 # Check for xapian classes. 128 classname = self._xapian_classes.get(type(obj), None) 129 if classname is not None: 130 return True 131 # Check for subclasses of xapian classes. 132 for classobj, classname in self._xapian_classes.iteritems(): 133 if isinstance(obj, classobj): 134 return True 135 # Not a xapian class or subclass. 136 return False
137
138 - def _get_xap_name(self, obj, maybe_new=False):
139 """Get the name of a xapian class or method. 140 141 The mutex should be held when this is called. 142 143 """ 144 # Check if it's a xapian class, or subclass. 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 # Check if it's a xapian function. 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 # Check if it's a proxied object. 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 # Check if it's a proxied method. 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 # Check if it's a subclass of a xapian class. Note: this will only 176 # pick up subclasses, because the original classes are filtered out 177 # higher up. 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 # msg = '%s,%s' % ( 189 # datetime.datetime.fromtimestamp(time.time()).isoformat(), 190 # msg, 191 # ) 192 self._fd.write(msg) 193 self._fd.flush() 194 finally: 195 self._fd_mutex.release()
196
197 - def _repr_arg(self, arg):
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
239 - def _repr_args(self, args):
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
250 - def _get_call_id(self):
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
271 - def log_call(self, call, *args):
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 # No access to an members, so no need to acquire mutex. 297 exc = traceback.format_exception_only(etype, value) 298 self._log("EXCEPT%s:%s\n" % (call_id, ''.join(exc).strip()))
299
300 - def log_retval(self, ret, call_id):
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 # If it's a xapian object, return a proxy for it. 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 # Not a xapian object - just return it. 319 self._log(msg) 320 return ret
321
322 - def _obj_gone(self, num):
323 """Log that an object has been deleted. 324 325 """ 326 self._log('DEL:#%d\n' % num)
327
328 -class LoggedProxy(object):
329 """A proxy for a xapian object, which logs all calls made on the object. 330 331 """
332 - def __init__(self, obj):
333 self.__obj = obj
334
335 - def __getattribute__(self, name):
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
344 - def __iter__(self):
345 obj = object.__getattribute__(self, '_LoggedProxy__obj') 346 return obj.__iter__()
347
348 - def __len__(self):
349 obj = object.__getattribute__(self, '_LoggedProxy__obj') 350 return obj.__len__()
351
352 - def __repr__(self):
353 obj = object.__getattribute__(self, '_LoggedProxy__obj') 354 return '<LoggedProxy of %s >' % obj.__repr__()
355
356 - def __str__(self):
357 obj = object.__getattribute__(self, '_LoggedProxy__obj') 358 return obj.__str__()
359
360 -class LoggedProxyMethod(object):
361 """A proxy for a xapian method, which logs all calls made on the method. 362 363 """
364 - def __init__(self, real, proxyobj):
365 """Make a proxy for the method. 366 367 """ 368 self.real = real 369 self.proxyobj = proxyobj
370
371 - def __call__(self, *args):
372 """Call the proxied method, logging the call. 373 374 """ 375 return log(self, *args)
376
377 -def set_replay_path(logpath):
378 """Set the path for the replay log. 379 380 """ 381 global _replay_log 382 global _had_replay_log 383 if logpath is None: 384 _replay_log = None 385 else: 386 _had_replay_log = True 387 _replay_log = ReplayLog(logpath)
388
389 -def _unproxy_call_and_args(call, args):
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 # If we've never had a replay log in force, no need to unproxy objects. 411 global _had_replay_log 412 if not _had_replay_log: 413 return call(*args) 414 415 # Get unproxied versions of the call and arguments. 416 realcall, realargs = _unproxy_call_and_args(call, args) 417 418 # If we have no replay log currently, just do the call. 419 global _replay_log 420 replay_log = _replay_log 421 if replay_log is None: 422 return realcall(*realargs) 423 424 # We have a replay log: do a logged version of the call. 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 #set_replay_path('replay.log') 434