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

Last change on this file since 7092 was 7092, checked in by rwilson, 14 years ago

Added Windows code to logging resource usage method.

  • Property svn:executable set to *
File size: 9.3 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    if sys.platform != 'win32':
201        _proc_status = '/proc/%d/status' % os.getpid()
202        _scale = {'KB': 1024, 'MB': 1024*1024, 'GB': 1024*1024*1024,
203                  'kB': 1024, 'mB': 1024*1024, 'gB': 1024*1024*1024}
204
205        def _VmB(VmKey):
206            '''Get number of virtual bytes used.'''
207
208            # get pseudo file /proc/<pid>/status
209            try:
210                t = open(_proc_status)
211                v = t.read()
212                t.close()
213            except IOError:
214                return 0.0
215
216            # get VmKey line, eg: 'VmRSS: 999 kB\n ...
217            i = v.index(VmKey)
218            v = v[i:].split(None, 3)
219            if len(v) < 3:
220                return 0.0
221
222            # convert Vm value to bytes
223            return float(v[1]) * _scale[v[2]]
224
225        def memory(since=0.0):
226            '''Get virtual memory usage in bytes.'''
227
228            return _VmB('VmSize:') - since
229
230        def resident(since=0.0):
231            '''Get resident memory usage in bytes.'''
232
233            return _VmB('VmRSS:') - since
234
235        def stacksize(since=0.0):
236            '''Get stack size in bytes.'''
237
238            return _VmB('VmStk:') - since
239
240        msg = ('Resource usage: memory=%.1fMB resident=%.1fMB stacksize=%.1fMB'
241               % (memory()/_scale['MB'], resident()/_scale['MB'],
242                  stacksize()/_scale['MB']))
243        log(level, msg)
244    else:
245        # from http://code.activestate.com/recipes/511491/
246        try:
247            import ctypes
248            import _winreg
249        except:
250            log(CRITICAL, 'Windows resource usage not available')
251            return
252
253        kernel32 = ctypes.windll.kernel32
254        c_ulong = ctypes.c_ulong
255        class MEMORYSTATUS(ctypes.Structure):
256            _fields_ = [('dwLength', c_ulong),
257                        ('dwMemoryLoad', c_ulong),
258                        ('dwTotalPhys', c_ulong),
259                        ('dwAvailPhys', c_ulong),
260                        ('dwTotalPageFile', c_ulong),
261                        ('dwAvailPageFile', c_ulong),
262                        ('dwTotalVirtual', c_ulong),
263                        ('dwAvailVirtual', c_ulong)
264                       ]
265           
266        memoryStatus = MEMORYSTATUS()
267        memoryStatus.dwLength = ctypes.sizeof(MEMORYSTATUS)
268        kernel32.GlobalMemoryStatus(ctypes.byref(memoryStatus))
269
270        msg = ('Resource usage: total memory=%.1fMB free memory=%.1fMB'
271               % (memoryStatus.dwTotalPhys/_scale['MB'],
272                  memoryStatus.dwAvailPhys/_scale['MB']))
273        log(level, msg)
274
275
276if __name__ == '__main__':
277##    critical('Testing exception capturing')
278    def test_it(num=100):
279        if num > 0:
280            test_it(num-1)
281        else:
282            resource_usage()
283
284    import numpy as num
285   
286    a = num.zeros((1000,1000), num.float)
287
288    test_it()
289    info('sys.version_info=%s, _new_python=%s'
290         % (str(sys.version_info), str(_new_python)))
Note: See TracBrowser for help on using the repository browser.