src/loggingSimple.py

   1 #!/usr/bin/env python
   2 # -*- coding: utf-8 -*-
   3
   4 """
   5 salomeTools logger. using logging package
   6
   7 | http://sametmax.com/ecrire-des-logs-en-python/
   8 |
   9 | Define two LoggerSat instances in salomeTools, no more need.
  10 |   - _loggerDefault as production/development logger
  11 |   - _loggerUnittest as unittest logger
  12 |
  13
  14 """
  15
  16
  17 import os
  18 import sys
  19 import time
  20 import random
  21 import logging as LOGI
  22
  23 from logging.handlers import BufferingHandler
  24 import pprint as PP
  25
  26 import src.debug as DBG  # Easy print stderr (for DEBUG only)
  27
  28 _verbose = False
  29 _name = "loggingSimple"
  30 _loggerDefaultName = 'SimpleDefaultLogger'
  31 _loggerUnittestName = 'SimpleUnittestLogger'
  32
  33 _STEP = LOGI.INFO - 1  # step level is just below INFO
  34 _TRACE = LOGI.INFO - 2  # trace level is just below STEP
  35
  36 LOGI.STEP = _STEP  # only for coherency,
  37 LOGI.TRACE = _TRACE  # only for coherency,
  38
  39 _knownLevels = "CRITICAL ERROR WARNING INFO STEP TRACE DEBUG".upper().split()
  40 _knownLevelsStr = "[%s]" % "|".join(_knownLevels)
  41
  42
  43 #################################################################
  44 # utilities methods
  45 #################################################################
  46
  47 def filterLevel(aLevel):
  48   """
  49   filter levels logging values from firsts characters levels.
  50   No case sensitive
  51
  52   | example:
  53   | 'i' -> 'INFO'
  54   | 'cRiT' -> 'CRITICAL'
  55   """
  56   aLev = aLevel.upper()
  57   knownLevels = _knownLevels
  58   maxLen = max([len(i) for i in knownLevels])
  59   for i in range(maxLen):
  60     for lev in knownLevels:
  61       if aLev == lev[:i]:
  62         # DBG.write("filterLevel", "%s -> %s" % (aLevel, lev))
  63         return lev
  64   msg = "Unknown level '%s', accepted are:\n%s" % (aLev, ", ".join(knownLevels))
  65   return msg
  66   # raise Exception(msg)
  67
  68
  69 def indent(msg, nb, car=" "):
  70   """indent nb car (spaces) multi lines message except first one"""
  71   s = msg.split("\n")
  72   res = ("\n" + car * nb).join(s)
  73   return res
  74
  75
  76 def indentUnittest(msg, prefix=" | "):
  77   """
  78   indent multi lines message except first one with prefix.
  79   prefix default is designed for less spaces for size logs files
  80   and keep logs human eye readable
  81   """
  82   s = msg.split("\n")
  83   res = ("\n" + prefix).join(s)
  84   return res
  85
  86
  87 def log(msg, force=False):
  88   """elementary log when no logging.Logger yet"""
  89   prefix = "---- %s.log: " % _name
  90   nb = len(prefix)
  91   if _verbose or force:
  92     print(prefix + indent(msg, nb))
  93
  94
  95 # just for debug info where is import logging
  96 log("import logging on %s" % LOGI.__file__)
  97
  98
  99 def getStrDirLogger(logger):
 100   """
 101   Returns multi line string for logger description, with dir(logger).
 102   Used for debug
 103   """
 104   lgr = logger  # shortcut
 105   msg = "%s(name=%s, dateLogger=%s):\n%s\n"
 106   cName = lgr.__class__.__name__
 107   res = msg % (cName, lgr.name, lgr.dateLogger, PP.pformat(dir(lgr)))
 108   return res
 109
 110
 111 def getStrHandler(handler):
 112   """
 113   Returns one line string for handler description
 114   (as inexisting __repr__)
 115   to avoid create inherited classe(s) handler
 116   """
 117   h = handler  # shortcut
 118   msg = "%s(name=%s)"
 119   cName = h.__class__.__name__
 120   # get_name absent in logging 0.5.0.5 python 2.6
 121   res = msg % (cName, h._name)
 122   return res
 123
 124
 125 def getStrShort(msg):
 126   """Returns short string for msg (as first caracters without line feed"""
 127   # log("getStrShort " + str(msg), True)
 128   res = msg.replace("\n", "//")[0:30]
 129   return res
 130
 131
 132 def getStrLogRecord(logRecord):
 133   """
 134   Returns one line string for simple logging LogRecord description
 135   """
 136   msg = "LogRecord(level='%s', msg='%s...')"
 137   shortMsg = getStrShort(logRecord.msg)
 138   levelName = logRecord.levelname
 139   res = msg % (levelName, shortMsg)
 140   return res
 141
 142
 143 def getListOfStrLogRecord(listOfLogRecord):
 144   """
 145   Returns one line string for logging LogRecord description
 146   """
 147   res = [getStrLogRecord(l) for l in listOfLogRecord]
 148   return res
 149
 150
 151 #################################################################
 152 # salometools logger classes
 153 #################################################################
 154
 155 try:
 156   unicode
 157   _unicode = True
 158 except NameError:
 159   _unicode = False
 160
 161
 162 def getMessage(self):
 163   """
 164   modified from logging.__init__.LogRecord.getMessage,
 165   better message on format error
 166   Return the message for this LogRecord.
 167
 168   Return the message for this LogRecord after merging any user-supplied
 169   arguments with the message.
 170   """
 171   if not _unicode:  # if no unicode support...
 172     msg = str(self.msg)
 173   else:
 174     msg = self.msg
 175     if not isinstance(msg, basestring):
 176       try:
 177         msg = str(self.msg)
 178       except UnicodeError:
 179         msg = self.msg  # Defer encoding till later
 180   if self.args:
 181     try:  # better message on format error
 182       msg = msg % self.args
 183     except Exception as e:
 184       msg = "ERROR: %s with args %s" % (msg, PP.pformat(self.args))
 185       log(msg, True)
 186   return msg
 187
 188
 189 LOGI.LogRecord.getMessage = getMessage  # better message if error
 190
 191
 192 #################################################################
 193 class LoggerSimple(LOGI.Logger, object): # object force new-style classes in logging 0.5.0.5 python 2.6
 194   """
 195   Inherited class logging.Logger for logger salomeTools
 196
 197   | add a level STEP as log.step(msg)
 198   | add a level TRACE as log.trace(msg)
 199   | below log.info(msg)
 200   | above log.debug(msg)
 201   | to assume message step inside files xml 'command's internal traces'
 202   | to assume store long log asci in files txt outside files xml
 203   |
 204   | see: /usr/lib64/python2.7/logging/__init__.py etc.
 205   """
 206
 207   def __init__(self, name, level=LOGI.INFO):
 208     """
 209     Initialize the logger with a name and an optional level.
 210     """
 211     super(LoggerSimple, self).__init__(name, level)
 212     LOGI.addLevelName(_STEP, "STEP")
 213     LOGI.addLevelName(_TRACE, "TRACE")
 214     self.dateLogger = "NoDateLogger"
 215     self.dateHour = None  # datehour of main command
 216     self.isClosed = False
 217     self.STEP = _STEP
 218     self.TRACE = _TRACE
 219
 220   def close(self):
 221     """
 222     final stuff for logger, done at end salomeTools
 223     flushed and closed xml files have to be not overriden/appended
 224     """
 225     if self.isClosed:
 226       raise Exception("logger closed yet: %s" % self)
 227     log("close stuff logger %s" % self)  # getStrDirLogger(self)
 228     for handl in list(self.handlers):  # get original list
 229       log("close stuff handler %s" % getStrHandler(handl))
 230       handl.close()  # Tidy up any resources used by the handler.
 231       self.removeHandler(handl)
 232     # todo etc
 233     self.isClosed = True  # done at end of execution
 234     return
 235
 236   def __repr__(self):
 237     """one line string representation"""
 238     msg = "%s(name=%s, dateLogger=%s, handlers=%s)"
 239     cName = self.__class__.__name__
 240     h = [getStrHandler(h) for h in self.handlers]
 241     h = "[" + ", ".join(h) + "]"
 242     res = msg % (cName, self.name, self.dateLogger, h)
 243     return res
 244
 245   def trace(self, msg, *args, **kwargs):
 246     """
 247     Log 'msg % args' with severity '_TRACE'.
 248     """
 249     log("trace stuff logger '%s' msg '%s...'" % (self.name, getStrShort(msg)))
 250     if self.isEnabledFor(_TRACE):
 251       self._log(_TRACE, msg, args, **kwargs)
 252
 253   def step(self, msg, *args, **kwargs):
 254     """
 255     Log 'msg % args' with severity '_STEP'.
 256     """
 257     log("step stuff logger '%s' msg '%s...'" % (self.name, getStrShort(msg)))
 258     if self.isEnabledFor(_STEP):
 259       self._log(_STEP, msg, args, **kwargs)
 260
 261   def setLevelMainHandler(self, level):
 262     handl =  self.handlers[0]  # get main handler
 263     log("setLevelMainHandler %s" % level)
 264     handl.setLevel(level)
 265
 266
 267 #################################################################
 268 class UnittestFormatter(LOGI.Formatter, object): # object force new-style classes in logging 0.5.0.5 python 2.6
 269   """
 270   this formatter prefixes level name and indents all messages
 271   """
 272   def format(self, record):
 273     # print "", record.levelname #type(record), dir(record)
 274     # nb = len("2018-03-17 12:15:41 :: INFO     :: ")
 275     res = super(UnittestFormatter, self).format(record)
 276     res = indentUnittest(res)
 277     return res
 278
 279 #################################################################
 280 class DefaultFormatter(LOGI.Formatter, object): # object force new-style classes in logging 0.5.0.5 python 2.6
 281   """
 282   this formatter prefixes level name and indents all messages but INFO stay "as it"
 283   """
 284   def format(self, record):
 285     # print "", record.levelname #type(record), dir(record)
 286     # nb = len("2018-03-17 12:15:41 :: INFO     :: ")
 287     if record.levelname == "INFO":
 288       res = record.getMessage()
 289     else:
 290       res = super(DefaultFormatter, self).format(record)
 291       res = indentUnittest(res)
 292     return res
 293
 294
 295 #################################################################
 296 class UnittestStream(object):
 297   """
 298   write my stream class
 299   only write and flush are used for the streaming
 300
 301   | https://docs.python.org/2/library/logging.handlers.html
 302   | https://stackoverflow.com/questions/31999627/storing-logger-messages-in-a-string
 303   """
 304
 305   def __init__(self):
 306     self._logs = ''
 307
 308   def getLogs(self):
 309     return self._logs
 310
 311   def getLogsAndClear(self):
 312     res = self._logs
 313     self._logs = ''
 314     return res
 315
 316   def write(self, astr):
 317     """final method called when message is logged"""
 318     # log("UnittestStream.write('%s')" % astr, True) # for debug ...
 319     self._logs += astr
 320
 321   def flush(self):
 322     pass
 323
 324   def __str__(self):
 325     return self._logs
 326
 327
 328 #################################################################
 329 class StreamHandlerSimple(LOGI.StreamHandler, object): # object force new-style classes in logging 0.5.0.5 python 2.6
 330   """
 331   A handler class which writes logging records, appropriately formatted,
 332   to a stream. Note that this class does not close the stream, as
 333   sys.stdout or sys.stderr may be used.
 334
 335   from logging.StreamHandler class,
 336   modified for 'no return' mode line if '...' at end of record message
 337   """
 338
 339   def emit(self, record):
 340     """
 341     Emit a record.
 342
 343     If a formatter is specified, it is used to format the record.
 344     The record is then written to the stream with a trailing newline.  If
 345     exception information is present, it is formatted using
 346     traceback.print_exception and appended to the stream.  If the stream
 347     has an 'encoding' attribute, it is used to determine how to do the
 348     output to the stream.
 349     """
 350     # log("StreamHandlerSimple.emit('%s')" % record, True) # for debug ...
 351     try:
 352       msg = self.format(record)
 353       stream = self.stream
 354       fs = '%s\n'
 355       ufs = u'%s\n'
 356       if not _unicode:  # if no unicode support...
 357         stream.write(fs % msg)
 358       else:
 359         try:
 360           if (isinstance(msg, unicode) and
 361             getattr(stream, 'encoding', None)):
 362             # ufs = u'%s\n'
 363             try:
 364               stream.write(ufs % msg)
 365             except UnicodeEncodeError:
 366               # Printing to terminals sometimes fails. For example,
 367               # with an encoding of 'cp1251', the above write will
 368               # work if written to a stream opened or wrapped by
 369               # the codecs module, but fail when writing to a
 370               # terminal even when the codepage is set to cp1251.
 371               # An extra encoding step seems to be needed.
 372               stream.write((ufs % msg).encode(stream.encoding))
 373           else:
 374             stream.write(fs % msg)
 375         except UnicodeError:
 376           stream.write(fs % msg.encode("UTF-8"))
 377       self.flush()
 378     except (KeyboardInterrupt, SystemExit):
 379       raise
 380     except:
 381       self.handleError(record)
 382
 383
 384
 385 #################################################################
 386 # methods to define two LoggerSimple instances in salomeTools,
 387 # no more need
 388 #################################################################
 389 def initLoggerAsDefault(logger, fmt=None, level=None):
 390   """
 391   init logger as prefixed message and indented message if multi line
 392   exept info() outed 'as it' without any format.
 393   level could be modified during execution
 394   """
 395   log("initLoggerAsDefault name=%s\nfmt='%s' level='%s'" % (logger.name, fmt, level))
 396   #handler = StreamHandlerSimple(sys.stdout)  # Logging vers console
 397   handler = LOGI.StreamHandler(sys.stdout)  # Logging vers console
 398   # set_name absent in logging 0.5.0.5 python 2.6
 399   handler._name = logger.name + "_console"
 400   if fmt is not None:
 401     # formatter = UnittestFormatter(fmt, "%y-%m-%d %H:%M:%S")
 402     formatter = DefaultFormatter(fmt, "%y-%m-%d %H:%M:%S")
 403     handler.setFormatter(formatter)
 404   handler.idCommandHandlers = 0
 405   logger.addHandler(handler)
 406   # as RootLogger is level WARNING
 407   # my logger is not notset but low, handlers needs setlevel greater
 408   logger.setLevel(LOGI.DEBUG)
 409   # import src/debug as DBG
 410   # tmp = (logger.getEffectiveLevel(), LOGI.NOTSET, logger.level, logger.parent.level)
 411   # DBG.write("logger levels tmp, True)
 412   if level is not None:  # level could be modified during execution
 413     handler.setLevel(level)  # on screen log as user wants
 414   else:
 415     handler.setLevel(LOGI.INFO)  # on screen no log step, which are in xml files
 416   return
 417
 418
 419 def initLoggerAsUnittest(logger, fmt=None, level=None):
 420   """
 421   init logger as silent on stdout/stderr
 422   used for retrieve messages in memory for post execution unittest
 423   https://docs.python.org/2/library/logging.handlers.html
 424   """
 425   log("initLoggerAsUnittest name=%s\nfmt='%s' level='%s'" % (logger.name, fmt, level))
 426   stream = UnittestStream()
 427   handler = LOGI.StreamHandler(stream)  # Logging vers stream
 428   # set_name absent in logging 0.5.0.5 python 2.6
 429   handler._name = logger.name + "_unittest"
 430   if fmt is not None:
 431     # formatter = LOGI.Formatter(fmt, "%Y-%m-%d %H:%M:%S")
 432     formatter = UnittestFormatter(fmt, "%Y-%m-%d %H:%M:%S")
 433     handler.setFormatter(formatter)
 434   handler.idCommandHandlers = 0
 435   logger.addHandler(handler)
 436   logger.stream = stream
 437   logger.getLogs = stream.getLogs
 438   logger.getLogsAndClear = stream.getLogsAndClear
 439   if level is not None:
 440     logger.setLevel(level)
 441   else:
 442     logger.setLevel(LOGI.DEBUG)
 443
 444
 445 def getDefaultLogger():
 446   log("getDefaultLogger %s" % _loggerDefaultName)
 447   # case multithread may be problem as not LOGI._acquireLock()
 448   previousClass = LOGI._loggerClass
 449   LOGI.setLoggerClass(LoggerSimple)  # to get LoggerSimple instance with trace etc.
 450   res = LOGI.getLogger(_loggerDefaultName)
 451   LOGI.setLoggerClass(previousClass)
 452   return res
 453
 454
 455 def getUnittestLogger():
 456   log("getUnittestLogger %s" % _loggerUnittestName)
 457   # case multithread may be problem as not LOGI._acquireLock()
 458   previousClass = LOGI._loggerClass
 459   LOGI.setLoggerClass(LoggerSimple)  # to get LoggerSimple instance with trace etc.
 460   res = LOGI.getLogger(_loggerUnittestName)
 461   LOGI.setLoggerClass(previousClass)
 462   return res
 463
 464
 465 #################################################################
 466 # small tests as demonstration, see unittest also
 467 #################################################################
 468 def testLogger_2(logger):
 469   """small test"""
 470   # print getStrDirLogger(logger)
 471   logger.debug('test logger debug')
 472   logger.trace('test logger trace')
 473   logger.info('test logger info')
 474   logger.warning('test logger warning')
 475   logger.error('test logger error')
 476   logger.critical('test logger critical')
 477   logger.info('\ntest logger info:\n- second line\n- third line\n')
 478   logger.warning('test logger warning:\n- second line\n- third line')
 479
 480 def testMain_2():
 481   print("\n**** DEFAULT logger")
 482   logdef = getDefaultLogger()
 483   # use of setColorLevelname <color>...<reset>, so do not use %(levelname)-8s
 484   initLoggerAsDefault(logdef, '%(levelname)-8s :: %(message)s', level=LOGI.DEBUG)
 485   testLogger_2(logdef)
 486
 487   print("\n**** UNITTEST logger")
 488   loguni = getUnittestLogger()
 489   initLoggerAsUnittest(loguni, '%(asctime)s :: %(levelname)-8s :: %(message)s', level=LOGI.DEBUG)
 490   testLogger_2(loguni)  # is silent
 491   # log("loguni.getLogs():\n%s" % loguni.getLogs())
 492   print("loguni.streamUnittest:\n%s" % loguni.getLogs())
 493
 494
 495 #################################################################
 496 # in production, or not (if __main__)
 497 #################################################################
 498 if __name__ == "__main__":
 499   # for example, not in production
 500   # get path to salomeTools sources
 501   curdir = os.path.dirname(os.path.dirname(__file__))
 502   # Make the src & commands package accessible from all code
 503   sys.path.insert(0, curdir)
 504   testMain_2()
 505   # here we have sys.exit()
 506 else:
 507   # in production
 508   # get two LoggerSat instance used in salomeTools, no more needed.
 509   _loggerDefault = getDefaultLogger()
 510   _loggerUnittest = getUnittestLogger()
 511   initLoggerAsDefault(_loggerDefault, '%(levelname)-8s :: %(message)s')
 512   initLoggerAsUnittest(_loggerUnittest, '%(asctime)s :: %(levelname)s :: %(message)s')