HWRF  trunk@4391
log.py
1 """!Configures logging.
2 
3 This module configures logging for stdout, stderr and the jlogfile.
4 It also contains the jlogger, a logger.Logger object that is used to
5 log directly to the jlogfile, and jlogdomain: a string name of the
6 logger domain for the jlogfile."""
7 
8 ##@var __all__
9 # Symbols epxorted by "from produtil.log import *"
10 __all__ = [ 'configureLogging','jlogger','jlogdomain','postmsg',
11  'MasterLogFormatter','JLogFormatter','stdout_is_stderr',
12  'MasterLogHandler','JLogHandler','set_jlogfile' ]
13 
14 import logging, os, sys, traceback, threading
16 
17 ##@var logthread
18 # string for log messages to indicate thread number/name
19 logthread=''
20 
21 ##@var jlogdomain
22 # Logging domain for the jlogfile
23 jlogdomain='jlog'
24 
25 ##@var jlogger
26 # A logging.Logger for the jlogdomain
27 jlogger=logging.getLogger(jlogdomain)
28 
29 ##@var jloghandler
30 # A logging.LogHandler for the jlogger
31 jloghandler=None
32 
33 class ThreadLogger(logging.Logger):
34  """!Custom logging.Logger that inserts thread information."""
35  def makeRecord(self,name,lvl,fn,lno,msg,*args,**kwargs):
36  """!Replaces the logging.Logger.makeRecord() with a new
37  implementation that inserts thread information from
38  threading.current_thread()
39  @param name,lvl,fn,lno,msg,args,kwargs Log message information.
40  See the Python logging module documentation for details."""
41  ct=threading.current_thread()
42  msg='[%s] %s'%(str(ct.name),str(msg))
43  x=logging.Logger.makeRecord(self,name,lvl,fn,lno,msg,*args,**kwargs)
44  return x
45 
46 def postmsg(message):
47  """!Sends the message to the jlogfile logging stream at level INFO.
48 
49  This is identical to:
50  @code
51  jlogger.info(message).
52  @endcode
53  @param message the message to log."""
54  return jlogger.info(message)
55 
56 def set_jlogfile(filename):
57  """!Tells the jlogger to log to the specified file instead of the
58  current jlogfile. Also updates the jlogfile environment variable.
59  The argument must be a filename.
60  @param filename the new jlogfile"""
61  jloghandler.set_jlogfile(filename)
62  os.environ['jlogfile']=filename
63 
64 class MasterLogFormatter(logging.Formatter):
65  """!This is a custom log formatter that inserts the thread or
66  process (logthread) that generated the log message. Also, it
67  always directly calls formatException from format, ensuring that
68  cached information is not used. That allows a subclass
69  (JLogFormatter) to ignore exceptions."""
70  def __init__(self,fmt=None,datefmt=None,logthread=None):
71  """!MasterLogFormatter constructor
72  @param fmt the log message format
73  @param datefmt the date format
74  @param logthread the thread name for logging
75  @note See the Python logging module documentation for details."""
76  logging.Formatter.__init__(self,fmt=fmt,datefmt=datefmt)
77  self._logthread=None
78  @property
79  def logthread(self):
80  """!The name of the batch thread or process that generated log
81  messages, if the LogRecord does not supply that already."""
82  global logthread # use global value if I don't have one
83  if self._logthread is None: return logthread
84  return self._logthread
85  def format(self, record):
86  """!Replaces the logging.Formatter.format() function.
87 
88  We need to override this due to a "feature" in the
89  Formatter.format: It ignores formatException (never calls it)
90  and caches the exception info, even if the formatter is not
91  supposed to output it.
92  @param record the log record to format
93  @note See the Python logging module documentation for details."""
94  global logthread
95  record.message = record.getMessage()
96  if self._fmt.find("%(asctime)") >= 0:
97  record.asctime = self.formatTime(record, self.datefmt)
98  if 'logthread' not in record.__dict__:
99  record.__dict__['logthread']=self.logthread
100  s = self._fmt % record.__dict__
101  if 'exc_info' in record.__dict__ and record.exc_info is not None:
102  e = self.formatException(record.exc_info)
103  if e:
104  rec2=dict(record.__dict__)
105  for line in str(e).splitlines():
106  rec2['message']=line
107  s="%s\n%s"%( s, self._fmt % rec2 )
108  return s
109 
111  """!This subclass of MasterLogFormatter does not include exception
112  information in the log file. This is done to prevent cluttering
113  of the log file."""
114  def formatException(self, ei):
115  """!Returns nothing to indicate no exception information should
116  be printed.
117  @param ei the exception information to ignore"""
118 
120  """!Returns True if it can determine that stdout and stderr are the
121  same file or terminal. Returns False if it can determine they are
122  not, or if the result is inconclusive."""
123  try:
124  if os.fstat(sys.stdout.fileno()) == os.fstat(sys.stderr.fileno()):
125  return True
126  if sys.stdout.isatty() and sys.stderr.isatty():
127  return True
128  except Exception as e:
129  pass
130  return False
131 
132 class MasterLogHandler(logging.Handler):
133  """!Custom LogHandler for the master process of a multi-process job.
134 
135  This is a custom logging Handler class used for multi-process or
136  multi-job batch scripts. It has a higher minimum log level for
137  messages not sent to the jlogfile domain. Also, for every log
138  message, the log file is opened, the message is written and the
139  file is closed. This is done to mimic the postmsg command.
140  Exception information is never sent to the log file."""
141  def __init__(self,logger,jlogdomain,otherlevels,joformat,jformat):
142  """!MasterLogHandler constructor
143  @param logger The logging.Logger for the master process.
144  @param jlogdomain The logging domain for the jlogfile.
145  @param otherlevels Log level for any extrema to go to the jlogfile.
146  @param joformat Log format for other streams.
147  @param jformat Log format for the jlogfile stream."""
148  logging.Handler.__init__(self)
149  self._logger=logger
150  self._otherlevels=otherlevels
151  self._jlogdomain=jlogdomain
152  self._joformat=joformat
153  self._jformat=jformat
154  def stringify_record(self,record):
155  """!Convert a log record to a string.
156  @note See the Python logging module documentation for details.
157  @returns a string message to print"""
158  assert(isinstance(self._joformat,MasterLogFormatter))
159  assert(isinstance(self._jformat,MasterLogFormatter))
160  global logthread
161  if record.name==self._jlogdomain:
162  # Reformat for jlogdomain:
163  message=self._jformat.format(record)
164  elif record.levelno<self._otherlevels:
165  return None # log level too low
166  else:
167  message=self._joformat.format(record)
168  message+='\n'
169  return message
170  def emit(self,record):
171  """!Write a log message.
172  @param record the log record
173  @note See the Python logging module documentation for details."""
174  message=self.stringify_record(record)
175  self._logger.write(message)
176 
178  """!Custom LogHandler for the jlogfile.
179 
180  This is a custom logging Handler class for the jlogfile. It has a
181  higher minimum log level for messages not sent to the jlogfile
182  domain. Also, for every log message, the log file is opened, the
183  message is written and the file is closed. This is done to mimic
184  the postmsg command. Exception information is never sent to the
185  log file."""
186  def emit(self,record):
187  """!Write a log message.
188  @param record the log record
189  @note See the Python logging module documentation for details."""
190  message=self.stringify_record(record)
191  if message is None: return
192  if isinstance(self._logger,basestring):
193  # Open the file, write and close it, to mimic the postmsg script:
194  dirn=os.path.dirname(self._logger)
195  if not os.path.isdir(dirn):
196  # NOTE: Cannot use produtil.fileop.makedirs here due
197  # to order of module loads (fileop needs log, so log
198  # cannot need fileop):
199  for x in xrange(10):
200  try:
201  os.makedirs(dirn)
202  except EnvironmentError as e:
203  if os.path.isdir(dirn):
204  break
205  elif os.path.exists(dirn):
206  raise
207  elif x<9:
208  continue
209  raise
210  with open(self._logger,'at') as f:
211  f.write(message)
212  else:
213  self._logger.write(message)
214  def set_jlogfile(self, filename):
215  """!Set the location of the jlogfile
216  @param filename The path to the jlogfile."""
217  if not isinstance(filename,basestring):
218  raise TypeError(
219  'In JLogHandler.set_jlogfile, the filename must be a '
220  'string. You passed a %s %s.'
221  %(type(filename).__name__,repr(filename)))
222  self._logger=filename
223 
224 def mpi_redirect(threadname,stderrfile,stdoutfile,
225  masterlevel=logging.WARNING,
226  openmode=None,logger=None):
227  """!Used to split to multiple logging streams.
228 
229  When the Python script splits itself into multiple processes via
230  MPI, this function is called to redirect stdout to stdoutfile,
231  stderr to stderrfile, and produce a new logging stream to the
232  original stderr, with a logging level set to masterlevel. That
233  new logging stream is called the "master log" and will receive any
234  messages at level masterlevel or higher, and any messages sent to
235  the jlogdomain.
236 
237  This can also be used to redirect ONLY stdout, in which case no
238  master logging stream is set up. That is requested by
239  stderrfile=None.
240  @param threadname the name of this process for logging purposes
241  @param stderrfile file to receive stderr
242  @param stdoutfile file to receive stdout
243  @param masterlevel log level to send to master log stream
244  @param openmode integer mode to use when opening files
245  @param logger a logging.Logger for logging errors while splitting
246  the log stream. """
247  if logger is None: logger=logging.getLogger('produtil')
248  if openmode is None:
249  openmode=os.O_CREAT|os.O_WRONLY|os.O_APPEND
250  elif not isinstance(openmode,int):
251  raise TypeError(
252  "In mpiRedirect, the openmode must be an int, not a "
253  +type(openmode).__name__)
254  if not isinstance(stdoutfile,basestring):
255  raise TypeError(
256  "In mpiRedirect, the stdoutfile must be a string, not a "
257  +type(stdoutfile).__name__)
258  if stderrfile is not None and not isinstance(stderrfile,basestring):
259  raise TypeError(
260  "In mpiRedirect, the stderrfile must be a string or None, not a "
261  +type(stderrfile).__name__)
262  if not isinstance(threadname,basestring):
263  raise TypeError(
264  "In mpiRedirect, the threadname must be a string, not a "
265  +type(threadname))
266 
267  global logthread
268  logthread='['+str(threadname)+']'
269 
270  logger.warning('Redirecting stdout to "%s" for thread %s'
271  %(stdoutfile,logthread))
272  fd=os.open(stdoutfile,openmode)
273  os.dup2(fd,1)
274 
275  if stderrfile is not None:
276  logger.warning('Redirecting stderr to "%s" for thread %s'
277  %(stderrfile,logthread))
278 
279  olderrfd=os.dup(2)
280  olderr=os.fdopen(olderrfd,'at',0)
281 
282  if(stdoutfile!=stderrfile):
283  # Only reopen if stderr differs from stdout.
284  fd=os.open(str(stderrfile),openmode)
285  os.dup2(fd,2)
286 
287  oformat=MasterLogFormatter(
288  "%(asctime)s.%(msecs)03d %(name)s %(logthread)s (%(filename)s:"
289  "%(lineno)d) %(levelname)s: %(message)s",
290  "%m/%d %H:%M:%S")
291 
292  # Create the master log handler. It will send to the old stderr
293  # (from before the redirection), and send everything from
294  # masterlevel and higher from any logging domain. Anything sent
295  # to the jlogfile, at any level, will be sent to the master log
296  # file as well.
297  mloghandler=MasterLogHandler(olderr,jlogdomain,masterlevel,oformat,
298  oformat)
299  logger.warning('Turning on logging of high priority messages to '
300  'original stderr stream.')
301  if masterlevel!=logging.NOTSET: mloghandler.setLevel(masterlevel)
302  logging.getLogger().addHandler(mloghandler)
303 
304 def configureLogging(jlogfile=None,
305  level=logging.INFO, # all messages filtered by this
306  jloglevel=logging.INFO,
307  japplevel=logging.ERROR, # should be >=jloglevel
308  eloglevel=logging.WARNING,
309  ologlevel=logging.NOTSET,
310  thread_logger=False):
311  """!Configures log output to stderr, stdout and the jlogfile
312 
313  Configures log file locations and logging levels for all streams.
314 
315  @note Important notes when choosing levels:
316  * level - sets the global minimum log level. Anything below this
317  level will be discarded regardless of other settings.
318  * jloglevel - this limit is applied before japplevel
319 
320  @param jlogfile path to the jlogfile. Default: use
321  os.environ('jlogfile') if set. Otherwise, stderr.
322  @param level minimum logging level globally. Set to INFO by default.
323  Change this to logging.DEBUG if you're debugging the program.
324  @param jloglevel minimum logging level to send to jlogfile
325  @param japplevel minimum logging level to send to jlogfile from all
326  domains except that specified in jlogdomain. Be careful
327  when changing this as it logs directly to the WCOSS-wide
328  jlogfile in operations.
329  @param eloglevel minimum logging level to send to stderr from ALL logs
330  Set to None to disable stderr logging
331  @param ologlevel minimum logging level to send to stdout from ALL logs
332  Default: logging.NOTSET (no filtering)
333  Set to None to disable stdout logging.
334  @param thread_logger True to include the thread name in log messages."""
335 
336  global jloghandler
337 
338  if thread_logger:
339  logging.setLoggerClass(produtil.log.ThreadLogger)
340 
341  root=logging.getLogger()
342  if level!=logging.NOTSET:
343  root.setLevel(level) # set global minimum logging level
344 
345  # Configure log formatting:
346  jlog=logging.getLogger('jlogfile')
347  jobstr=os.environ.get('job',None)
348  if jobstr is None:
350  jobstr=str(jobstr).replace('(','_').replace(')','_').replace('%','_')
351  # Format for jlogfile domain logging to jlogfile:
352  jformat=JLogFormatter(
353  "%(asctime)sZ "+jobstr+"-%(levelname)s: %(logthread)s %(message)s",
354  "%m/%d %H:%M:%S")
355  # Format for other domains logging to jlogfile is the same, but
356  # with the domain added:
357  joformat=JLogFormatter(
358  "%(asctime)sZ "+jobstr+
359  "-%(name)s: %(levelname)s: %(logthread)s %(message)s",
360  "%m/%d %H:%M:%S")
361  # For stdout/stderr, a more verbose version with milliseconds,
362  # file and line numbers:
363  oformat=logging.Formatter(
364  "%(asctime)s.%(msecs)03d %(name)s (%(filename)s:%(lineno)d) "
365  "%(levelname)s: %(message)s",
366  "%m/%d %H:%M:%S")
367 
368  if stdout_is_stderr():
369  # Configure combined stdout+stderr logging:
370  loglevel=min(ologlevel,eloglevel)
371  logstream=logging.StreamHandler(sys.stderr)
372  logstream.setFormatter(oformat)
373  if loglevel!=logging.NOTSET: logstream.setLevel(loglevel)
374  root.addHandler(logstream)
375  else:
376  # Configure stdout logging:
377  if ologlevel is not None:
378  ologstream=logging.StreamHandler(sys.stdout)
379  ologstream.setFormatter(oformat)
380  if ologlevel!=logging.NOTSET: ologstream.setLevel(ologlevel)
381  root.addHandler(ologstream)
382 
383  # Configure stderr logging:
384  if eloglevel is not None:
385  elogstream=logging.StreamHandler(sys.stderr)
386  elogstream.setFormatter(oformat) # same format as stdout
387  if eloglevel!=logging.NOTSET: elogstream.setLevel(eloglevel)
388  root.addHandler(elogstream)
389 
390  # Configure jlogfile logging:
391  # jlogfile domain: INFO and higher
392  # all domains: ERROR and higher
393  if jlogfile is None:
394  # Try to get the jlogfile from the environment if none is specified:
395  var=str(os.environ.get('jlogfile',''))
396  if len(var)>0: jlogfile=var
397  # If we still don't have the jlogfile, use stderr:
398  jlogfile=str(jlogfile) if jlogfile is not None else sys.stderr
399  jloghandler=JLogHandler(jlogfile,jlogdomain,japplevel,joformat,jformat)
400  if jloglevel!=logging.NOTSET: jloghandler.setLevel(jloglevel)
401 
402  root.addHandler(jloghandler)
def set_jlogfile(self, filename)
Set the location of the jlogfile.
Definition: log.py:214
def set_jlogfile(filename)
Tells the jlogger to log to the specified file instead of the current jlogfile.
Definition: log.py:56
def stringify_record(self, record)
Convert a log record to a string.
Definition: log.py:154
This subclass of MasterLogFormatter does not include exception information in the log file...
Definition: log.py:110
def __init__(self, logger, jlogdomain, otherlevels, joformat, jformat)
Custom LogHandler for the master process of a multi-process job.
Definition: log.py:141
def __init__
MasterLogFormatter constructor.
Definition: log.py:70
def postmsg(message)
Sends the message to the jlogfile logging stream at level INFO.
Definition: log.py:46
def logthread(self)
The name of the batch thread or process that generated log messages, if the LogRecord does not supply...
Definition: log.py:79
This is a custom log formatter that inserts the thread or process (logthread) that generated the log ...
Definition: log.py:64
def configureLogging
Configures log output to stderr, stdout and the jlogfile.
Definition: log.py:310
def stdout_is_stderr()
Returns True if it can determine that stdout and stderr are the same file or terminal.
Definition: log.py:119
def mpi_redirect
Used to split to multiple logging streams.
Definition: log.py:226
def emit(self, record)
Write a log message.
Definition: log.py:170
Provides information about the batch system.
Definition: batchsystem.py:1
def makeRecord(self, name, lvl, fn, lno, msg, args, kwargs)
Replaces the logging.Logger.makeRecord() with a new implementation that inserts thread information fr...
Definition: log.py:35
def formatException(self, ei)
Returns nothing to indicate no exception information should be printed.
Definition: log.py:114
Custom LogHandler for the master process of a multi-process job.
Definition: log.py:132
def format(self, record)
Replaces the logging.Formatter.format() function.
Definition: log.py:85
def jobname
Get the batch job name.
Definition: batchsystem.py:84
Custom LogHandler for the jlogfile.
Definition: log.py:177
def emit(self, record)
Write a log message.
Definition: log.py:186
Custom logging.Logger that inserts thread information.
Definition: log.py:33