1
2
3
4
5
6
7
8
9 """Verbose output and debugging facility
10
11 Examples:
12 from verbosity import verbose, debug; debug.active = [1,2,3]; debug(1, "blah")
13
14 """
15
16 __docformat__ = 'restructuredtext'
17
18 from sys import stdout, stderr
19 from sets import Set
20
21
22
23
24
25
26
27
28
29
31 """
32 Base class to provide logging
33 """
34
36 """Initialize the logger with a set of handlers to use for output
37
38 Each hanlder must have write() method implemented
39 """
40 if handlers == None:
41 handlers = [stdout]
42 self.__close_handlers = []
43 self._setHandlers(handlers)
44 self.__lfprev = True
45 self.__crprev = 0
46
49
51 """Set list of handlers for the log.
52
53 A handler can be opened files, stdout, stderr, or a string, which
54 will be considered a filename to be opened for writing
55 """
56 handlers_ = []
57 self._closeOpenedHandlers()
58 for handler in handlers:
59 if isinstance(handler, basestring):
60 try:
61 handler = {'stdout' : stdout,
62 'stderr' : stderr}[handler.lower()]
63 except:
64 try:
65 handler = open(handler, 'w')
66 self.__close_handlers.append(handler)
67 except:
68 raise RuntimeError, \
69 "Cannot open file %s for writing by the logger" \
70 % handler
71 handlers_.append(handler)
72 self.__handlers = handlers_
73
75 """Close opened handlers (such as opened logfiles
76 """
77 for handler in self.__close_handlers:
78 handler.close()
79
81 """Return active handlers
82 """
83 return self.__handlers
84
85
86 - def __call__(self, msg, lf=True, cr=False, *args, **kwargs):
87 """
88 Write msg to each of the handlers.
89
90 It can append a newline (lf = Line Feed) or return
91 to the beginning before output and to take care about
92 cleaning previous message if present
93
94 it appends a newline (lf = Line Feed) since most commonly each
95 call is a separate message
96 """
97 if kwargs.has_key('msgargs'):
98 msg = msg % kwargs['msgargs']
99
100 if cr:
101 msg_ = ""
102 if self.__crprev > 0:
103
104 msg_ = "\r%s\r" % (" "*self.__crprev)
105 msg_ += msg
106 self.__crprev = len(msg)
107 msg = msg_
108
109
110 lf = False
111 else:
112 self.__crprev += len(msg)
113
114 if lf:
115 msg = msg + "\n"
116 self.__crprev = 0
117
118 for handler in self.__handlers:
119 handler.write(msg)
120 try:
121 handler.flush()
122 except:
123
124 pass
125
126 self.__lfprev = lf
127
128 handlers = property(fget=_getHandlers, fset=_setHandlers)
129 lfprev = property(fget=lambda self:self.__lfprev)
130
131
132
134 """
135 Logger which prints based on level -- ie everything which is smaller
136 than specified level
137 """
138
139 - def __init__(self, level=0, indent=" ", *args, **kwargs):
140 """Define level logger.
141
142 It is defined by
143 `level`, int: to which messages are reported
144 `indent`, string: symbol used to indent
145 """
146 Logger.__init__(self, *args, **kwargs)
147 self.__level = level
148 self.__indent = indent
149 self._setLevel(level)
150 self._setIndent(indent)
151
153 """Set logging level
154 """
155 ilevel = int(level)
156 if ilevel < 0:
157 raise ValueError, \
158 "Negative verbosity levels (got %d) are not supported" \
159 % ilevel
160 self.__level = ilevel
161
162
164 """Either to indent the lines based on message log level"""
165 self.__indent = "%s" % indent
166
167
168 - def __call__(self, level, msg, *args, **kwargs):
169 """
170 Write msg and indent using self.indent it if it was requested
171
172 it appends a newline since most commonly each call is a separate
173 message
174 """
175 if level <= self.level:
176 if self.lfprev and self.indent:
177
178 msg = self.indent*level + msg
179 Logger.__call__(self, msg, *args, **kwargs)
180
181 level = property(fget=lambda self: self.__level, fset=_setLevel)
182 indent = property(fget=lambda self: self.__indent, fset=_setIndent)
183
184
186 """
187 Logger which prints a message for a given ID just once.
188
189 It could be used for one-time warning to don't overfill the output
190 with useless repeatative messages
191 """
192
194 """Define once logger.
195 """
196 Logger.__init__(self, *args, **kwargs)
197 self._known = {}
198
199
200 - def __call__(self, ident, msg, count=1, *args, **kwargs):
201 """
202 Write `msg` if `ident` occured less than `count` times by now.
203 """
204 if not self._known.has_key(ident):
205 self._known[ident] = 0
206
207 if count < 0 or self._known[ident] < count:
208 self._known[ident] += 1
209 Logger.__call__(self, msg, *args, **kwargs)
210
211
213 """
214 Logger which prints based on defined sets identified by Id.
215 """
216
217 - def __init__(self, register=None, active=None, printsetid=True,
218 *args, **kwargs):
229
230
232 """Set active logging set
233 """
234
235
236 from mvpa.misc import verbose
237 self.__active = []
238 registered_keys = self.__registered.keys()
239 for item in list(Set(active)):
240 if item == '':
241 continue
242 if isinstance(item, basestring):
243 if item.upper() == "ALL":
244 verbose(2, "Enabling all registered debug handlers")
245 self.__active = registered_keys
246 break
247
248 regexp = re.compile("^%s$" % item)
249 matching_keys = filter(regexp.match, registered_keys)
250 self.__active += matching_keys
251 else:
252 self.__active.append(item)
253
254 self.__active = list(Set(self.__active))
255 self.__maxstrlength = max([len(str(x)) for x in self.__active] + [0])
256 if len(self.__active):
257 verbose(2, "Enabling debug handlers: %s" % `self.__active`)
258
259
261 """Either to print set Id at each line"""
262 self.__printsetid = printsetid
263
264
265 - def __call__(self, setid, msg, *args, **kwargs):
266 """
267 Write msg
268
269 It appends a newline since most commonly each call is a separate
270 message
271 """
272 if not self.__registered.has_key(setid):
273 self.__registered[setid] = "No Description"
274
275 if setid in self.__active:
276 if self.__printsetid:
277 msg = "[%%-%ds] " % self.__maxstrlength % (setid) + msg
278 Logger.__call__(self, msg, *args, **kwargs)
279
280
281 - def register(self, setid, description):
282 """ "Register" a new setid with a given description for easy finding
283 """
284
285 if self.__registered.has_key(setid):
286 raise ValueError, \
287 "Setid %s is already known with description '%s'" % \
288 ( `setid`, self.__registered[setid] )
289 self.__registered[setid] = description
290
291
293 """Given a string listing registered(?) setids, make then active
294 """
295
296
297 self.active = value.split(",")
298
299
300 printsetid = property(fget=lambda self: self.__printsetid, \
301 fset=_setPrintsetid)
302 active = property(fget=lambda self: self.__active, fset=_setActive)
303 registered = property(fget=lambda self: self.__registered)
304
305
306 if __debug__:
307
308 import os, re
309 import traceback
310 import time
311
313 """Return stat information on current process.
314
315 Usually it is needed to know where the memory is gone, that is
316 why VmSize is the default for the field to spit out
317 TODO: Spit out multiple fields. Use some better way than parsing proc
318 """
319
320 fd = open('/proc/%d/status'%os.getpid())
321 lines = fd.readlines()
322 fd.close()
323 return filter(lambda x:re.match('^%s:'%field, x), lines)[0].strip()
324
325
327 """Simple helper class to provide relative time it took from previous
328 invocation"""
329
330 - def __init__(self, format="%3.3f sec"):
331 self.__prev = None
332 self.__format = format
333
335 dt = 0.0
336 ct = time.time()
337 if not self.__prev is None:
338 dt = ct - self.__prev
339 self.__prev = ct
340 return self.__format % dt
341
342
344 """
345 Logger for debugging purposes.
346
347 Expands SetLogger with ability to print some interesting information
348 (named Metric... XXX) about current process at each debug printout
349 """
350
351 _known_metrics = {
352 'vmem' : lambda : parseStatus(field='VmSize'),
353 'pid' : lambda : parseStatus(field='Pid'),
354 'asctime' : time.asctime
355 }
356
357
358 - def __init__(self, metrics=None, offsetbydepth=True, *args, **kwargs):
369
370
372 """Register some metric to report
373
374 func can be either a function call or a string which should
375 correspond to known metrics
376 """
377
378 if isinstance(func, basestring):
379 if func in ['all', 'ALL']:
380 func = self._known_metrics.keys()
381
382 if isinstance(func, basestring):
383 if DebugLogger._known_metrics.has_key(func):
384 func = DebugLogger._known_metrics[func]
385 else:
386 raise ValueError, \
387 "Unknown name %s for metric in DebugLogger" % \
388 func + " Known metrics are " + \
389 `DebugLogger._known_metrics.keys()`
390 elif isinstance(func, list):
391 for item in func:
392 self.registerMetric(item)
393 return
394
395 if not func in self.__metrics:
396 try:
397 from mvpa.misc import debug
398 debug("DBG", "Registering metric %s" % func)
399 self.__metrics.append(func)
400 except:
401 pass
402
403
404 - def __call__(self, setid, msg, *args, **kwargs):
405 if not setid in self.active:
406
407
408 return
409
410 msg_ = ""
411
412 for metric in self.__metrics:
413 msg_ += " %s" % `metric()`
414
415 if len(msg_)>0:
416 msg_ = "{%s}" % msg_
417
418
419 if self._offsetbydepth:
420 level = len(traceback.extract_stack())-2
421 else:
422 level = 1
423
424 SetLogger.__call__(self, setid, "DBG%s:%s%s" %
425 (msg_, " "*level, msg),
426 *args, **kwargs)
427
428
430 self._offsetbydepth = b
431
432 offsetbydepth = property(fget=lambda x:x._offsetbydepth,
433 fset=_setOffsetByDepth)
434