source: trunk/anuga_core/source/anuga/utilities/log.py @ 7848

Last change on this file since 7848 was 7848, checked in by steve, 14 years ago

Changed the logging levels in log.py so that the information about openning the
file ./anuga.log is now only an info log as opposed to critical log. I.e. by default
doesn't write to the console.

  • Property svn:executable set to *
File size: 9.5 KB
Line 
1#!/usr/bin/env python
2
3'''
4A simple logging module that logs to the console and a logfile, and has a
5configurable threshold loglevel for each of console and logfile output.
6
7Use it this way:
8    import anuga.utilities.log as log
9
10    # configure my logging
11    log.console_logging_level = log.INFO
12    log.log_logging_level = log.DEBUG
13    log.log_filename = './my.log'
14
15    # log away!
16    log.debug('A message at DEBUG level')
17    log.info('Another message, INFO level')
18
19This class uses the 'borg' pattern - there is never more than one instance
20of log data.  See the URL for the basic idea used here: modules *are*
21singletons!
22
23<http://www.suttoncourtenay.org.uk/duncan/accu/pythonpatterns.html>
24
25Until the first call to log() the user is free to play with the module data
26to configure the logging.
27
28Note that this module uses some features of the logging package that were
29introduced in python2.5.  If running on earlier versions, the following
30features are disabled:
31    . Calling module name + line number
32'''
33
34import os
35import sys
36import traceback
37import logging
38
39DefaultConsoleLogLevel = logging.CRITICAL
40DefaultFileLogLevel = logging.INFO
41
42
43################################################################################
44# Module variables - only one copy of these, ever.
45#
46# The console logging level is set to a high level, like CRITICAL.  The logfile
47# logging is set lower, between DEBUG and CRITICAL.  The idea is to log least to
48# the console, but ensure that everything that goes to the console *will* also
49# appear in the log file.  There is code to ensure log <= console levels.
50#
51# If console logging level is set to CRITICAL+1 then nothing will print on the
52# console.
53################################################################################
54
55# flag variable to determine if logging set up or not
56_setup = False
57
58# logging level for the console
59console_logging_level = DefaultConsoleLogLevel
60
61# logging level for the logfile
62log_logging_level = DefaultFileLogLevel
63
64# The default name of the file to log to.
65log_filename = os.path.join('.', 'anuga.log')
66
67# set module variables so users don't have to do 'import logging'.
68CRITICAL = logging.CRITICAL
69ERROR = logging.ERROR
70WARNING = logging.WARNING
71INFO = logging.INFO
72DEBUG = logging.DEBUG
73NOTSET = logging.NOTSET
74
75# set _new_python to True if python version 2.5 or later
76_new_python = (sys.version_info >= 0x02050000)      # 2.5.x.x
77
78
79################################################################################
80# Module code.
81################################################################################
82
83def log(msg, level=None):
84    '''Log a message at a particular loglevel.
85
86    msg:    The message string to log.
87    level:  The logging level to log with (defaults to console level).
88
89    The first call to this method (by anybody) initializes logging and
90    then logs the message.  Subsequent calls just log the message.
91    '''
92
93    global _setup, log_logging_level
94    fname = '' # default to no frame name if it cannot be found
95    lnum = 0
96
97    # have we been setup?
98    if not _setup:
99        # sanity check the logging levels, require console >= file
100        if log_logging_level > console_logging_level:
101            log_logging_level = console_logging_level
102
103        # setup the file logging system
104        if _new_python:
105            fmt = '%(asctime)s %(levelname)-8s %(mname)25s:%(lnum)-4d|%(message)s'
106        else:
107            fmt = '%(asctime)s %(levelname)-8s|%(message)s'
108        logging.basicConfig(level=log_logging_level, format=fmt,
109                            filename=log_filename, filemode='w')
110
111        # define a console handler which writes to sys.stdout
112        console = logging.StreamHandler(sys.stdout)
113        console.setLevel(console_logging_level)
114        formatter = logging.Formatter('%(message)s')
115        console.setFormatter(formatter)
116        logging.getLogger('').addHandler(console)
117
118        # catch exceptions
119        sys.excepthook = log_exception_hook
120
121        # tell the world how we are set up
122        start_msg = ("Logfile is '%s' with logging level of %s, "
123                     "console logging level is %s"
124                     % (log_filename,
125                        logging.getLevelName(log_logging_level),
126                        logging.getLevelName(console_logging_level)))
127        if _new_python:
128            logging.log(logging.INFO, start_msg,
129                        extra={'mname': __name__, 'lnum': 0})
130        else:
131            logging.log(logging.INFO, start_msg)
132
133        # mark module as *setup*
134        _setup = True
135
136    # if logging level not supplied, assume console level
137    if level is None:
138        level = console_logging_level
139
140    # get caller information - look back for first module != <this module name>
141    frames = traceback.extract_stack()
142    frames.reverse()
143    try:
144        (_, mod_name) = __name__.rsplit('.', 1)
145    except ValueError:
146        mod_name = __name__
147    for (fpath, lnum, mname, _) in frames:
148        (fname, _) = os.path.basename(fpath).rsplit('.', 1)
149        if fname != mod_name:
150            break
151
152    # why are we here? ... Oh yes! Log the message!
153    if _new_python:
154        logging.log(level, msg, extra={'mname': fname, 'lnum': lnum})
155    else:
156        logging.log(level, msg)
157
158
159def log_exception_hook(type, value, tb):
160    '''Hook function to process uncaught exceptions.
161
162    type:   Type of exception.
163    value:  The exception data.
164    tb:     Traceback object.
165
166    This has the same interface as sys.excepthook().
167    '''
168
169    msg = '\n' + ''.join(traceback.format_exception(type, value, tb))
170    critical(msg)
171
172   
173################################################################################
174# Shortcut routines to make for simpler user code.
175################################################################################
176
177def debug(msg=''):
178    '''Shortcut for log(DEBUG, msg).'''
179
180    log(msg, logging.DEBUG)
181
182
183def info(msg=''):
184    '''Shortcut for log(INFO, msg).'''
185
186    log(msg, logging.INFO)
187
188
189def warning(msg=''):
190    '''Shortcut for log(WARNING, msg).'''
191
192    log(msg, logging.WARNING)
193
194
195def error(msg=''):
196    '''Shortcut for log(ERROR, msg).'''
197
198    log(msg, logging.ERROR)
199
200
201def critical(msg=''):
202    '''Shortcut for log(CRITICAL, msg).'''
203
204    log(msg, logging.CRITICAL)
205
206
207def resource_usage(level=logging.INFO):
208    '''Log memory usage at given log level.'''
209
210    _scale = {'KB': 1024, 'MB': 1024*1024, 'GB': 1024*1024*1024,
211              'kB': 1024, 'mB': 1024*1024, 'gB': 1024*1024*1024}
212
213    if sys.platform != 'win32':
214        _proc_status = '/proc/%d/status' % os.getpid()
215       
216        def _VmB(VmKey):
217            '''Get number of virtual bytes used.'''
218
219            # get pseudo file /proc/<pid>/status
220            try:
221                t = open(_proc_status)
222                v = t.read()
223                t.close()
224            except IOError:
225                return 0.0
226
227            # get VmKey line, eg: 'VmRSS: 999 kB\n ...
228            i = v.index(VmKey)
229            v = v[i:].split(None, 3)
230            if len(v) < 3:
231                return 0.0
232
233            # convert Vm value to bytes
234            return float(v[1]) * _scale[v[2]]
235
236        def memory(since=0.0):
237            '''Get virtual memory usage in bytes.'''
238
239            return _VmB('VmSize:') - since
240
241        def resident(since=0.0):
242            '''Get resident memory usage in bytes.'''
243
244            return _VmB('VmRSS:') - since
245
246        def stacksize(since=0.0):
247            '''Get stack size in bytes.'''
248
249            return _VmB('VmStk:') - since
250
251        msg = ('Resource usage: memory=%.1fMB resident=%.1fMB stacksize=%.1fMB'
252               % (memory()/_scale['MB'], resident()/_scale['MB'],
253                  stacksize()/_scale['MB']))
254        log(msg, level)
255    else:
256        # Windows code from: http://code.activestate.com/recipes/511491/
257        try:
258            import ctypes
259            import _winreg
260        except:
261            log(level, 'Windows resource usage not available')
262            return
263
264        kernel32 = ctypes.windll.kernel32
265        c_ulong = ctypes.c_ulong
266        c_ulonglong = ctypes.c_ulonglong
267        class MEMORYSTATUSEX(ctypes.Structure):
268            _fields_ = [('dwLength', c_ulong),
269                        ('dwMemoryLoad', c_ulong),
270                        ('ullTotalPhys', c_ulonglong),
271                        ('ullAvailPhys', c_ulonglong),
272                        ('ullTotalPageFile', c_ulonglong),
273                        ('ullAvailPageFile', c_ulonglong),
274                        ('ullTotalVirtual', c_ulonglong),
275                        ('ullAvailVirtual', c_ulonglong),
276                        ('ullAvailExtendedVirtual', c_ulonglong)
277                       ]
278
279        memoryStatusEx = MEMORYSTATUSEX()
280        memoryStatusEx.dwLength = ctypes.sizeof(MEMORYSTATUSEX)
281        kernel32.GlobalMemoryStatusEx(ctypes.byref(memoryStatusEx))
282
283        msg = ('Resource usage: total memory=%.1fMB free memory=%.1fMB'
284               % (memoryStatusEx.ullTotalPhys/_scale['MB'],
285                  memoryStatusEx.ullAvailPhys/_scale['MB']))
286        log(msg, level)
287
288
289################################################################################
290
291if __name__ == '__main__':
292    critical('#' * 80)
293    warning('Test of logging...')
294    log('CRITICAL+1', CRITICAL+1)
295    log('CRITICAL', CRITICAL)
296    log('CRITICAL-1', CRITICAL-1)
297    log('CRITICAL-2', CRITICAL-2)
298    log('default - CRITICAL?')
299
300    def test_it(num=100):
301        if num > 0:
302            test_it(num-1)
303        else:
304            resource_usage()
305
306    import numpy as num
307   
308    a = num.zeros((1000,1000), num.float)
309
310    info('sys.version_info=%s, _new_python=%s'
311         % (str(sys.version_info), str(_new_python)))
312    test_it()
Note: See TracBrowser for help on using the repository browser.