review logging again; code that runs in client and/or server now logs in the right...
[sfa.git] / sfa / util / sfalogging.py
1 #!/usr/bin/python
2
3 import os, sys
4 import traceback
5 import logging, logging.handlers
6
7 CRITICAL=logging.CRITICAL
8 ERROR=logging.ERROR
9 WARNING=logging.WARNING
10 INFO=logging.INFO
11 DEBUG=logging.DEBUG
12
13 # a logger that can handle tracebacks 
14 class _SfaLogger:
15     def __init__ (self,logfile=None,loggername=None,level=logging.INFO):
16         # default is to locate loggername from the logfile if avail.
17         if not logfile:
18             loggername='console'
19             handler=logging.StreamHandler()
20             handler.setFormatter(logging.Formatter("%(levelname)s %(message)s"))
21         else:
22             if not loggername:
23                 loggername=os.path.basename(logfile)
24             try:
25                 handler=logging.handlers.RotatingFileHandler(logfile,maxBytes=1000000, backupCount=5) 
26             except IOError:
27                 # This is usually a permissions error becaue the file is
28                 # owned by root, but httpd is trying to access it.
29                 tmplogfile=os.getenv("TMPDIR", "/tmp") + os.path.sep + os.path.basename(logfile)
30                 handler=logging.handlers.RotatingFileHandler(tmplogfile,maxBytes=1000000, backupCount=5) 
31             handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s"))
32
33         self.logger=logging.getLogger(loggername)
34         self.logger.setLevel(level)
35         self.logger.addHandler(handler)
36         self.loggername=loggername
37
38     def setLevel(self,level):
39         self.logger.setLevel(level)
40
41     # shorthand to avoid having to import logging all over the place
42     def setLevelDebug(self):
43         self.logger.setLevel(logging.DEBUG)
44
45     # define a verbose option with s/t like
46     # parser.add_option("-v", "--verbose", action="count", dest="verbose", default=0)
47     # and pass the coresponding options.verbose to this method to adjust level
48     def setLevelFromOptVerbose(self,verbose):
49         if verbose==0:
50             self.logger.setLevel(logging.WARNING)
51         elif verbose==1:
52             self.logger.setLevel(logging.INFO)
53         elif verbose==2:
54             self.logger.setLevel(logging.DEBUG)
55
56     ####################
57     def wrap(fun):
58         def wrapped(self,msg,*args,**kwds):
59             native=getattr(self.logger,fun.__name__)
60             return native(msg,*args,**kwds)
61         #wrapped.__doc__=native.__doc__
62         return wrapped
63
64     @wrap
65     def critical(): pass
66     @wrap
67     def error(): pass
68     @wrap
69     def warning(): pass
70     @wrap
71     def info(): pass
72     @wrap
73     def debug(): pass
74     
75     # logs an exception - use in an except statement
76     def log_exc(self,message):
77         self.error("%s BEG TRACEBACK"%message+"\n"+traceback.format_exc().strip("\n"))
78         self.error("%s END TRACEBACK"%message)
79     
80     def log_exc_critical(self,message):
81         self.critical("%s BEG TRACEBACK"%message+"\n"+traceback.format_exc().strip("\n"))
82         self.critical("%s END TRACEBACK"%message)
83     
84     # for investigation purposes, can be placed anywhere
85     def log_stack(self,message):
86         to_log="".join(traceback.format_stack())
87         self.debug("%s BEG STACK"%message+"\n"+to_log)
88         self.debug("%s END STACK"%message)
89
90 ####################
91 # import-related operations go in this file
92 _import_logger=_SfaLogger(logfile='/var/log/sfa_import.log')
93 # servers log into /var/log/sfa.log
94 _server_logger=_SfaLogger(logfile='/var/log/sfa.log')
95 # clients use the console
96 _console_logger=_SfaLogger()
97
98 # default is to use the server-side logger
99 _the_logger=_server_logger
100
101 # clients would change the default by issuing one of these call
102 def sfa_logger_goes_to_console():
103     current_module=sys.modules[globals()['__name__']]
104     current_module._the_logger=_console_logger
105
106 # clients would change the default by issuing one of these call
107 def sfa_logger_goes_to_import():
108     current_module=sys.modules[globals()['__name__']]
109     current_module._logger=_sfa_import_logger
110
111 # this is how to retrieve the 'right' logger
112 def sfa_logger():
113     return _the_logger
114
115 ########################################
116 import time
117
118 def profile(logger):
119     """
120     Prints the runtime of the specified callable. Use as a decorator, e.g.,
121     
122     @profile(logger)
123     def foo(...):
124         ...
125     """
126     def logger_profile(callable):
127         def wrapper(*args, **kwds):
128             start = time.time()
129             result = callable(*args, **kwds)
130             end = time.time()
131             args = map(str, args)
132             args += ["%s = %s" % (name, str(value)) for (name, value) in kwds.items()]
133             # should probably use debug, but then debug is not always enabled
134             logger.info("PROFILED %s (%s): %.02f s" % (callable.__name__, ", ".join(args), end - start))
135             return result
136         return wrapper
137     return logger_profile
138
139
140 if __name__ == '__main__': 
141     print 'testing sfalogging into logger.log'
142     logger=_SfaLogger('logger.log')
143     logger.critical("logger.critical")
144     logger.error("logger.error")
145     logger.warning("logger.warning")
146     logger.info("logger.info")
147     logger.debug("logger.debug")
148     logger.setLevel(logging.DEBUG)
149     logger.debug("logger.debug again")
150     
151     sfa_logger_goes_to_console()
152     my_logger=sfa_logger()
153     my_logger.info("redirected to console")
154
155     @profile(my_logger)
156     def sleep(seconds = 1):
157         time.sleep(seconds)
158
159     my_logger.info('console.info')
160     sleep(0.5)
161     my_logger.setLevel(logging.DEBUG)
162     sleep(0.25)
163