1 | #!/usr/bin/env python |
---|
2 | |
---|
3 | ''' |
---|
4 | A simple logging module that logs to the console and a logfile, and has a |
---|
5 | configurable threshold loglevel for each of console and logfile output. |
---|
6 | |
---|
7 | Use it this way: |
---|
8 | import anuga.utilities.log as log |
---|
9 | log.debug('A message at DEBUG level') |
---|
10 | log.info('Another message, INFO level') |
---|
11 | |
---|
12 | This class uses the 'borg' pattern - there is never more than one instance |
---|
13 | of log data. See |
---|
14 | <http://www.suttoncourtenay.org.uk/duncan/accu/pythonpatterns.html> |
---|
15 | for the basic idea used here: modules *are* singletons! |
---|
16 | |
---|
17 | Until the first call to log() the user is free to play with the module data |
---|
18 | to configure the logging. |
---|
19 | ''' |
---|
20 | |
---|
21 | import sys |
---|
22 | import os |
---|
23 | #import os.path |
---|
24 | import sys |
---|
25 | import traceback |
---|
26 | import logging |
---|
27 | |
---|
28 | |
---|
29 | ################################################################################ |
---|
30 | # Module variables - only one copy of these, ever. |
---|
31 | ################################################################################ |
---|
32 | |
---|
33 | # flag variable to determine if logging set up or not |
---|
34 | _setup = False |
---|
35 | |
---|
36 | # logging level for the console |
---|
37 | console_logging_level = logging.INFO |
---|
38 | |
---|
39 | # logging level for the logfile |
---|
40 | log_logging_level = logging.DEBUG |
---|
41 | |
---|
42 | # The name of the file to log to. |
---|
43 | log_filename = './anuga.log' |
---|
44 | |
---|
45 | |
---|
46 | ################################################################################ |
---|
47 | # Module code. |
---|
48 | ################################################################################ |
---|
49 | |
---|
50 | ## |
---|
51 | # @brief Log a message at a specified level. |
---|
52 | # @param level The loglevel to log with (logging.DEBUG, etc). |
---|
53 | # @param msg Message string to log. |
---|
54 | # @note First call of this method initializes the logging system. |
---|
55 | def log(level, msg): |
---|
56 | '''Log a message at a particular loglevel. |
---|
57 | |
---|
58 | The first call to this method (by anybody) initializes logging and |
---|
59 | then logs the message. Subsequent calls just log the message. |
---|
60 | ''' |
---|
61 | |
---|
62 | global _setup |
---|
63 | |
---|
64 | # have we been setup? |
---|
65 | if not _setup: |
---|
66 | # setup the file logging system |
---|
67 | fmt = '%(asctime)s %(levelname)-8s %(mname)25s:%(lnum)-4d|%(message)s' |
---|
68 | logging.basicConfig(level=log_logging_level, format=fmt, |
---|
69 | filename=log_filename, filemode='w') |
---|
70 | |
---|
71 | # define a console handler which writes to sys.stdout |
---|
72 | console = logging.StreamHandler(sys.stdout) |
---|
73 | console.setLevel(console_logging_level) |
---|
74 | formatter = logging.Formatter('%(message)s') |
---|
75 | console.setFormatter(formatter) |
---|
76 | logging.getLogger('').addHandler(console) |
---|
77 | |
---|
78 | # tell the world how we are set up |
---|
79 | start_msg = ("Logfile is '%s' with logging level of %s, " |
---|
80 | "console logging level is %s" |
---|
81 | % (log_filename, |
---|
82 | logging.getLevelName(log_logging_level), |
---|
83 | logging.getLevelName(console_logging_level))) |
---|
84 | logging.log(logging.CRITICAL, start_msg, |
---|
85 | extra={'mname': __name__, 'lnum': 0}) |
---|
86 | |
---|
87 | # mark module as *setup* |
---|
88 | _setup = True |
---|
89 | |
---|
90 | # get caller information - look back for first module != <this module name> |
---|
91 | frames = traceback.extract_stack() |
---|
92 | frames.reverse() |
---|
93 | for (mname, lnum, _, _) in frames: |
---|
94 | mname = os.path.basename(mname).rsplit('.', 1)[0] |
---|
95 | if mname != __name__: |
---|
96 | break |
---|
97 | |
---|
98 | logging.log(level, msg, extra={'mname': mname, 'lnum': lnum}) |
---|
99 | |
---|
100 | ################################################################################ |
---|
101 | # Shortcut routines to make for simpler user code. |
---|
102 | ################################################################################ |
---|
103 | |
---|
104 | ## |
---|
105 | # @brief Shortcut for log(DEBUG, msg). |
---|
106 | # @param msg Message string to log at logging.DEBUG level. |
---|
107 | def debug(msg): |
---|
108 | log(logging.DEBUG, msg) |
---|
109 | |
---|
110 | ## |
---|
111 | # @brief Shortcut for log(INFO, msg). |
---|
112 | # @param msg Message string to log at logging.INFO level. |
---|
113 | def info(msg): |
---|
114 | log(logging.INFO, msg) |
---|
115 | |
---|
116 | ## |
---|
117 | # @brief Shortcut for log(WARNING, msg). |
---|
118 | # @param msg Message string to log at logging.WARNING level. |
---|
119 | def warning(msg): |
---|
120 | log(logging.WARNING, msg) |
---|
121 | |
---|
122 | ## |
---|
123 | # @brief Shortcut for log(ERROR, msg). |
---|
124 | # @param msg Message string to log at logging.ERROR level. |
---|
125 | def error(msg): |
---|
126 | log(logging.ERROR, msg) |
---|
127 | |
---|
128 | ## |
---|
129 | # @brief Shortcut for log(CRITICAL, msg). |
---|
130 | # @param msg Message string to log at logging.CRITICAL level. |
---|
131 | def critical(msg): |
---|
132 | log(logging.CRITICAL, msg) |
---|
133 | |
---|
134 | def resource_usage(level=logging.CRITICAL): |
---|
135 | '''Log resource usage at given log level.''' |
---|
136 | |
---|
137 | if sys.platform != 'win32': |
---|
138 | _proc_status = '/proc/%d/status' % os.getpid() |
---|
139 | _scale = {'KB': 1024.0, 'MB': 1024.0*1024.0, 'GB': 1024.0*1024.0*1024.0, |
---|
140 | 'kB': 1024.0, 'mB': 1024.0*1024.0, 'gB': 1024.0*1024.0*1024.0} |
---|
141 | |
---|
142 | def _VmB(VmKey): |
---|
143 | '''Get number of virtual bytes used.''' |
---|
144 | |
---|
145 | # get pseudo file /proc/<pid>/status |
---|
146 | try: |
---|
147 | t = open(_proc_status) |
---|
148 | v = t.read() |
---|
149 | t.close() |
---|
150 | except IOError: |
---|
151 | return 0.0 |
---|
152 | |
---|
153 | # get VmKey line, eg: 'VmRSS: 999 kB\n ... |
---|
154 | i = v.index(VmKey) |
---|
155 | v = v[i:].split(None, 3) |
---|
156 | if len(v) < 3: |
---|
157 | return 0.0 |
---|
158 | |
---|
159 | # convert Vm value to bytes |
---|
160 | return float(v[1]) * _scale[v[2]] |
---|
161 | |
---|
162 | def memory(since=0.0): |
---|
163 | '''Get virtual memory usage in bytes.''' |
---|
164 | |
---|
165 | return _VmB('VmSize:') - since |
---|
166 | |
---|
167 | def resident(since=0.0): |
---|
168 | '''Get resident memory usage in bytes.''' |
---|
169 | |
---|
170 | return _VmB('VmRSS:') - since |
---|
171 | |
---|
172 | def stacksize(since=0.0): |
---|
173 | '''Get stack size in bytes.''' |
---|
174 | |
---|
175 | return _VmB('VmStk:') - since |
---|
176 | |
---|
177 | msg = ('Resource usage: memory=%.1f resident=%.1f stacksize=%.1f' |
---|
178 | % (memory()/_scale['GB'], resident()/_scale['GB'], |
---|
179 | stacksize()/_scale['GB'])) |
---|
180 | log(level, msg) |
---|
181 | else: |
---|
182 | pass |
---|