source: branches/numpy/anuga/utilities/log.py @ 7095

Last change on this file since 7095 was 7095, checked in by rwilson, 15 years ago

Fixed bug in Windows code.

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