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