]>
Commit | Line | Data |
---|---|---|
2eeaec19 RD |
1 | #---------------------------------------------------------------------------- |
2 | # Name: aglogging.py | |
3 | # Purpose: Utilities to help with logging | |
4 | # | |
5 | # Author: Jeff Norton | |
6 | # | |
7 | # Created: 01/04/05 | |
8 | # CVS-ID: $Id$ | |
9 | # Copyright: (c) 2005 ActiveGrid, Inc. | |
10 | # License: wxWindows License | |
11 | #---------------------------------------------------------------------------- | |
12 | ||
13 | import sys | |
14 | import os | |
15 | import re | |
16 | import traceback | |
17 | import logging | |
02b800ce | 18 | import logging.config |
2eeaec19 | 19 | from activegrid.util.lang import * |
02b800ce RD |
20 | import activegrid.util.objutils as objutils |
21 | import activegrid.util.sysutils as sysutils | |
2eeaec19 RD |
22 | |
23 | LEVEL_FATAL = logging.FATAL | |
24 | LEVEL_ERROR = logging.ERROR | |
25 | LEVEL_WARN = logging.WARN | |
26 | LEVEL_INFO = logging.INFO | |
27 | LEVEL_DEBUG = logging.DEBUG | |
28 | ||
02b800ce RD |
29 | EXCEPTION_INFO = 'exceptionInfo' |
30 | ||
31 | LOG_MODE_IDE = 1 | |
32 | LOG_MODE_TESTRUN = 2 | |
33 | LOG_MODE_RUN = 3 | |
34 | def initLogging(mode): | |
35 | configFile = None | |
36 | if (mode == LOG_MODE_IDE): | |
37 | configFile = os.getenv("AG_LOGCONFIG_IDE") | |
38 | elif (mode == LOG_MODE_TESTRUN): | |
39 | configFile = os.getenv("AG_LOGCONFIG_TESTRUN") | |
40 | else: | |
41 | configFile = os.getenv("AG_LOGCONFIG_RUN") | |
42 | if ((configFile == None) or not os.path.exists(configFile)): | |
43 | if (mode == LOG_MODE_IDE): | |
44 | configFile = "IDELog" | |
45 | elif (mode == LOG_MODE_TESTRUN): | |
46 | configFile = "TestRunLog" | |
47 | else: | |
48 | configFile = "RunLog" | |
49 | configFile = sysutils.mainModuleDir + "/py" + configFile + ".ini" | |
50 | if (os.path.exists(configFile)): | |
51 | fileConfig(configFile) | |
52 | else: | |
53 | defaultStream = sys.stderr | |
54 | if (mode == LOG_MODE_RUN): | |
55 | defaultStream = sys.stdout | |
56 | handler = logging.StreamHandler(defaultStream) | |
57 | handler.setLevel(logging.INFO) | |
58 | handler.setFormatter(logging.Formatter("%(asctime)s %(name)s %(levelname)s: %(message)s")) | |
59 | logging.getLogger().addHandler(handler) | |
60 | return configFile | |
61 | ||
62 | ag_debugLogger = logging.getLogger("activegrid.debug") | |
63 | ||
64 | def log(logger, level, msg, *params): | |
65 | if (logger == None): | |
66 | logger = ag_debugLogger | |
67 | apply(logger.log, (level, msg) + params) | |
68 | ||
69 | def fatal(logger, msg, *params): | |
70 | apply(logger.fatal, (msg,) + params) | |
71 | ||
72 | def error(logger, msg, *params): | |
73 | apply(logger.error, (msg,) + params) | |
74 | ||
75 | def warn(logger, msg, *params): | |
76 | apply(logger.warn, (msg,) + params) | |
77 | ||
78 | def info(logger, msg, *params): | |
79 | apply(logger.info, (msg,) + params) | |
80 | ||
81 | def debug(logger, msg, *params): | |
82 | if (logger == None): | |
83 | logger = ag_debugLogger | |
84 | apply(logger.debug, (msg,) + params) | |
85 | ||
86 | def setLevelFatal(logger): | |
87 | logger.setLevel(LEVEL_FATAL) | |
88 | ||
89 | def setLevelError(logger): | |
90 | logger.setLevel(LEVEL_ERROR) | |
91 | ||
92 | def setLevelWarn(logger): | |
93 | logger.setLevel(LEVEL_WARN) | |
94 | ||
95 | def setLevelInfo(logger): | |
96 | logger.setLevel(LEVEL_INFO) | |
97 | ||
98 | def setLevelDebug(logger): | |
99 | logger.setLevel(LEVEL_DEBUG) | |
100 | ||
101 | def isEnabledForError(logger): | |
102 | return logger.isEnabledFor(LEVEL_ERROR) | |
103 | ||
104 | def isEnabledForWarn(logger): | |
105 | return logger.isEnabledFor(LEVEL_WARN) | |
106 | ||
107 | def isEnabledForInfo(logger): | |
108 | return logger.isEnabledFor(LEVEL_INFO) | |
109 | ||
110 | def isEnabledForDebug(logger): | |
111 | return logger.isEnabledFor(LEVEL_DEBUG) | |
112 | ||
2eeaec19 RD |
113 | TEST_MODE_NONE = 0 |
114 | TEST_MODE_DETERMINISTIC = 1 | |
115 | TEST_MODE_NON_DETERMINISTIC = 2 | |
116 | ||
117 | global agTestMode | |
118 | agTestMode = TEST_MODE_NONE | |
119 | ||
120 | def setTestMode(mode): | |
121 | global agTestMode | |
122 | agTestMode = mode | |
123 | ||
124 | def getTestMode(): | |
125 | global agTestMode | |
126 | return agTestMode | |
127 | ||
02b800ce RD |
128 | def testMode(normalObj, testObj=None, nonDeterministicObj=None): |
129 | testMode = getTestMode() | |
130 | if testMode > TEST_MODE_NONE: | |
131 | if ((nonDeterministicObj != None) and (testMode == TEST_MODE_NON_DETERMINISTIC)): | |
132 | return nonDeterministicObj | |
2eeaec19 RD |
133 | return testObj |
134 | return normalObj | |
135 | ||
136 | pythonFileRefPattern = asString(r'(?<=File ")[^"]*(#[^#]*")(, line )[0-9]*') | |
137 | phpFileRefPattern = asString(r'( in ).*#([^#]*#[^ ]*)(?= on line )') | |
138 | pathSepPattern = os.sep | |
139 | if (pathSepPattern == "\\"): | |
140 | pathSepPattern = "\\\\" | |
141 | pythonFileRefPattern = pythonFileRefPattern.replace("#", pathSepPattern) | |
142 | pythonFileRefPattern = re.compile(pythonFileRefPattern) | |
143 | phpFileRefPattern = phpFileRefPattern.replace("#", pathSepPattern) | |
144 | phpFileRefPattern = re.compile(phpFileRefPattern) | |
145 | ||
146 | def removeFileRefs(str): | |
147 | str = pythonFileRefPattern.sub(_fileNameReplacement, str) | |
148 | str = phpFileRefPattern.sub(_fileNameReplacementPHP, str) | |
149 | return str | |
150 | ||
151 | def removePHPFileRefs(str): | |
152 | str = phpFileRefPattern.sub(_fileNameReplacementPHP, str) | |
153 | return str | |
154 | ||
155 | def _fileNameReplacement(match): | |
156 | return "...%s" % match.group(1).replace(os.sep, "/") | |
157 | ||
158 | def _fileNameReplacementPHP(match): | |
159 | return "%s...%s" % (match.group(1), match.group(2).replace(os.sep, "/")) | |
160 | ||
02b800ce RD |
161 | def formatTraceback(tb=None): |
162 | if (tb == None): | |
163 | extype, val, tb = sys.exc_info() | |
164 | tbs = "\n" + "".join(traceback.format_tb(tb)) | |
2eeaec19 RD |
165 | return tbs |
166 | ||
02b800ce RD |
167 | def formatExceptionCause(cause, stacktrace=False): |
168 | if (cause == None): | |
169 | return "" | |
170 | tbs = "" | |
171 | if (stacktrace): | |
172 | tbs = formatTraceback() | |
173 | return "Caused by %s.%s: %s%s" % (cause.__module__, cause.__class__.__name__, str(cause), tbs) | |
174 | ||
175 | def addExceptionInfo(e, key, value): | |
176 | if not hasattr(e, EXCEPTION_INFO): | |
177 | try: | |
178 | setattr(e, EXCEPTION_INFO, {}) | |
179 | except: | |
180 | return # Make sure we still report the real exception even if we can't add the extra info | |
181 | if not e.exceptionInfo.has_key(key): # Never overwrite exception info since we assume earlier info is more specific | |
182 | e.exceptionInfo[key] = value | |
183 | ||
2eeaec19 | 184 | def reportException(out=None, stacktrace=False, diffable=False, exception=None): |
02b800ce RD |
185 | exstr = exceptionToString(exception, stacktrace, diffable) |
186 | if (out == None): | |
187 | print exstr | |
188 | else: | |
189 | print >> out, exstr | |
190 | ||
191 | def exceptionToString(exception=None, stacktrace=False, diffable=False): | |
192 | if (exception == None): | |
2eeaec19 RD |
193 | extype, val, t = sys.exc_info() |
194 | else: | |
02b800ce | 195 | extype = objutils.typeToString(exception) |
2eeaec19 RD |
196 | val = exception |
197 | if (stacktrace): | |
198 | e,v,t = sys.exc_info() | |
199 | if (diffable): | |
200 | exstr = removeFileRefs(str(val)) | |
201 | else: | |
202 | exstr = str(val) | |
02b800ce RD |
203 | if hasattr(val, EXCEPTION_INFO): |
204 | firstTime = True | |
205 | for infoKey, infoValue in getattr(val, EXCEPTION_INFO).items(): | |
206 | if firstTime: | |
207 | prefix = " EXTRA INFO:" | |
208 | firstTime = False | |
209 | else: | |
210 | prefix = "," | |
211 | exstr += ("%s %s=%s" % (prefix, infoKey, infoValue)) | |
212 | result = "Got Exception = %s: %s" % (extype, exstr) | |
2eeaec19 RD |
213 | if (stacktrace): |
214 | fmt = traceback.format_exception(extype, val, t) | |
215 | for s in fmt: | |
216 | if (diffable): | |
217 | s = removeFileRefs(s) | |
02b800ce RD |
218 | result = result + "\n" + s |
219 | return result | |
220 | ||
221 | def fileConfig(fname, defaults=None): | |
222 | """ | |
223 | This is copied from logging.config so that we could fix the class lookup of | |
224 | handlers. Previously handlers had to be defined in logging.handlers and we | |
225 | need to be able to define our own. | |
226 | """ | |
227 | import ConfigParser, string | |
228 | ||
229 | cp = ConfigParser.ConfigParser(defaults) | |
230 | if hasattr(cp, 'readfp') and hasattr(fname, 'readline'): | |
231 | cp.readfp(fname) | |
232 | else: | |
233 | cp.read(fname) | |
234 | #first, do the formatters... | |
235 | flist = cp.get("formatters", "keys") | |
236 | if len(flist): | |
237 | flist = string.split(flist, ",") | |
238 | formatters = {} | |
239 | for form in flist: | |
240 | sectname = "formatter_%s" % form | |
241 | opts = cp.options(sectname) | |
242 | if "format" in opts: | |
243 | fs = cp.get(sectname, "format", 1) | |
2eeaec19 | 244 | else: |
02b800ce RD |
245 | fs = None |
246 | if "datefmt" in opts: | |
247 | dfs = cp.get(sectname, "datefmt", 1) | |
248 | else: | |
249 | dfs = None | |
250 | f = logging.Formatter(fs, dfs) | |
251 | formatters[form] = f | |
252 | #next, do the handlers... | |
253 | #critical section... | |
254 | logging._acquireLock() | |
255 | try: | |
256 | ## try: | |
257 | #first, lose the existing handlers... | |
258 | logging._handlers.clear() | |
259 | #now set up the new ones... | |
260 | hlist = cp.get("handlers", "keys") | |
261 | if len(hlist): | |
262 | hlist = string.split(hlist, ",") | |
263 | handlers = {} | |
264 | fixups = [] #for inter-handler references | |
265 | for hand in hlist: | |
266 | ## try: | |
267 | sectname = "handler_%s" % hand | |
268 | classname = cp.get(sectname, "class") | |
269 | opts = cp.options(sectname) | |
270 | if "formatter" in opts: | |
271 | fmt = cp.get(sectname, "formatter") | |
272 | else: | |
273 | fmt = "" | |
274 | klass = None | |
275 | try: | |
276 | klass = eval(classname, vars(logging)) | |
277 | except: | |
278 | pass | |
279 | if (klass == None): | |
280 | klass = objutils.classForName(classname) | |
281 | args = cp.get(sectname, "args") | |
282 | args = eval(args, vars(logging)) | |
283 | h = apply(klass, args) | |
284 | if "level" in opts: | |
285 | level = cp.get(sectname, "level") | |
286 | h.setLevel(logging._levelNames[level]) | |
287 | if len(fmt): | |
288 | h.setFormatter(formatters[fmt]) | |
289 | #temporary hack for FileHandler and MemoryHandler. | |
290 | if klass == logging.handlers.MemoryHandler: | |
291 | if "target" in opts: | |
292 | target = cp.get(sectname,"target") | |
293 | else: | |
294 | target = "" | |
295 | if len(target): #the target handler may not be loaded yet, so keep for later... | |
296 | fixups.append((h, target)) | |
297 | handlers[hand] = h | |
298 | ## except Exception, e: #if an error occurs when instantiating a handler, too bad | |
299 | ## pass #this could happen e.g. because of lack of privileges | |
300 | #now all handlers are loaded, fixup inter-handler references... | |
301 | for fixup in fixups: | |
302 | h = fixup[0] | |
303 | t = fixup[1] | |
304 | h.setTarget(handlers[t]) | |
305 | #at last, the loggers...first the root... | |
306 | llist = cp.get("loggers", "keys") | |
307 | llist = string.split(llist, ",") | |
308 | llist.remove("root") | |
309 | sectname = "logger_root" | |
310 | root = logging.root | |
311 | log = root | |
312 | opts = cp.options(sectname) | |
313 | if "level" in opts: | |
314 | level = cp.get(sectname, "level") | |
315 | log.setLevel(logging._levelNames[level]) | |
316 | for h in root.handlers[:]: | |
317 | root.removeHandler(h) | |
318 | hlist = cp.get(sectname, "handlers") | |
319 | if len(hlist): | |
320 | hlist = string.split(hlist, ",") | |
321 | for hand in hlist: | |
322 | log.addHandler(handlers[hand]) | |
323 | #and now the others... | |
324 | #we don't want to lose the existing loggers, | |
325 | #since other threads may have pointers to them. | |
326 | #existing is set to contain all existing loggers, | |
327 | #and as we go through the new configuration we | |
328 | #remove any which are configured. At the end, | |
329 | #what's left in existing is the set of loggers | |
330 | #which were in the previous configuration but | |
331 | #which are not in the new configuration. | |
332 | existing = root.manager.loggerDict.keys() | |
333 | #now set up the new ones... | |
334 | for log in llist: | |
335 | sectname = "logger_%s" % log | |
336 | qn = cp.get(sectname, "qualname") | |
337 | opts = cp.options(sectname) | |
338 | if "propagate" in opts: | |
339 | propagate = cp.getint(sectname, "propagate") | |
340 | else: | |
341 | propagate = 1 | |
342 | logger = logging.getLogger(qn) | |
343 | if qn in existing: | |
344 | existing.remove(qn) | |
345 | if "level" in opts: | |
346 | level = cp.get(sectname, "level") | |
347 | logger.setLevel(logging._levelNames[level]) | |
348 | for h in logger.handlers[:]: | |
349 | logger.removeHandler(h) | |
350 | logger.propagate = propagate | |
351 | logger.disabled = 0 | |
352 | hlist = cp.get(sectname, "handlers") | |
353 | if len(hlist): | |
354 | hlist = string.split(hlist, ",") | |
355 | for hand in hlist: | |
356 | logger.addHandler(handlers[hand]) | |
357 | #Disable any old loggers. There's no point deleting | |
358 | #them as other threads may continue to hold references | |
359 | #and by disabling them, you stop them doing any logging. | |
360 | for log in existing: | |
361 | root.manager.loggerDict[log].disabled = 1 | |
362 | ## except: | |
363 | ## import traceback | |
364 | ## ei = sys.exc_info() | |
365 | ## traceback.print_exception(ei[0], ei[1], ei[2], None, sys.stderr) | |
366 | ## del ei | |
367 | finally: | |
368 | logging._releaseLock() |