Rewrite of moe.log using python logging

Bells, whistles, formatters, per-test logfiles included!

diff --git a/t/moe/log.py b/t/moe/log.py
index 592fb846b047bd7b1952c3e6866080aa1074b67d..c2ab4d23fd575cd2d5cdcdb74c36cfd2657617de 100644 (file)
--- a/t/moe/log.py
+++ b/t/moe/log.py
@@ -1,47 +1,89 @@
 #!/usr/bin/env python
 
-import sys
-import os
-import traceback
+import sys, os
+import logging 
+from logging import Logger, StreamHandler
 
-orig_stdout_fd = os.dup(1)
-orig_stderr_fd = os.dup(2)
-progress_file = os.fdopen(orig_stdout_fd, "w", 0)
 
-class MoeLog:
+class Loggers(Logger):
+  """Defines several logs:
 
-    def __init__(self):
-       self.verbosity = 0
-       self.progress_file = progress_file
-       self.log_file = None
+  `self` 
+    root log, which sends messages to `eval` and `test` logs
+  `self.eval` 
+    main log, initially a duplicated fd 2 (stderr)
+  `self.user` 
+    public progress log, initially a duplicated fd 1 (stdout)
+  `self.test` 
+    per-test log, initially no handler, to be directed to file like `{TEST}.log`
 
-    def open(self, name):
-       self.log_file = open(name, "w")
-       os.dup2(self.log_file.fileno(), 1)
-       os.dup2(self.log_file.fileno(), 2)
+  Currently, the logs and fd's get never closed. 
 
-    def say(self, msg):
-       if self.log_file:
-           self.log_file.write(msg)
+  TODO: formatters
+  WARN: Currently, the module changes fd's 1 and 2, this is a global change.
+  """
+  def __init__(self):
+    "Initialize loggers as described in class description."
+    Logger.__init__(self, '')
+    # Duplicate the fd's 
+    self.orig_stdout_fd = os.dup(1)
+    self.orig_stdout_file = os.fdopen(self.orig_stdout_fd, 'w', 0)
+    self.orig_stderr_fd = os.dup(2)
+    self.orig_stderr_file = os.fdopen(self.orig_stderr_fd, 'w', 0)
+    # Eval main logger  
+    self.eval = Logger('eval')
+    self.eval.addHandler(StreamHandler(self.orig_stderr_file))
+    # per-test logger
+    self.test = Logger('test')
+    self.test_handler = None
+    self.test_file = None
+    # user progress logger  
+    self.user = Logger('user')
+    self.eval.addHandler(StreamHandler(self.orig_stdout_file))
+ 
+    self.addHandler(self.test)
+    self.addHandler(self.eval)
+    self.debug('Logging initialized.')
 
-    def verbose(self, msg):
-       if self.verbosity and self.log_file:
-           self.log_file.write(msg)
+  def open_user_log(self, filename, level=logging.INFO):
+    """Open user (progress) logfile. Leaves logging to stdout active."""
+    h = StreamHandler(open(filename, 'w', 0))
+    h.setFormatter(Formatter('%(message)s'))
+    self.user.addHandler(h)
+    self.user.debug('Logging started')
 
-    def progress(self, msg):
-       if self.progress_file:
-           self.progress_file.write(msg)
+  def open_eval_log(self, filename, level, redirect_fds = True):
+    """Open user (progress) logfile. 
+    Leaves logging to stderr active. If told to, redirects fd's 1 and 2 to this file."""
+    self.eval_file = open(filename, 'w', 0)
+    self.eval_handler = StreamHandler(self.eval_file)
+    self.eval_handler.setFormatter(Formatter('%(message)s'))
+    self.user.addHandler(self.eval_handler)
+    if redirect_fds:
+      os.dup2(self.eval_file.fileno(), 1)
+      os.dup2(self.eval_file.fileno(), 2)
+    self.user.debug('Logging started')
 
-    def shout(self, msg):
-       self.say(msg)
-       self.progress(msg)
+  def open_test_log(self, filename, level):
+    """Open per-test log file, like "{TEST}.log". Also set handler level to `level`."""
+    self.debug('Opening per-test log %s' % filename)
+    if self.test_handler:
+      self.close_test_log()
+    self.test_file = open(filename, 'w')
+    self.test_handler = StreamHandler(self.test_file)
+    self.test.addHandler(self.test_handler)
+    self.test.setLevel(level)
+    self.test_handler.setFormatter(Formatter('%(asctime)s [%(levelno)s] %(message)s'))
+    self.test.debug('Logging started')
 
-    def flush(self):
-       self.log_file.flush()
-
-default = MoeLog()
-
-def fatal_exception():
-    os.dup2(orig_stderr_fd, 2)
-    traceback.print_exc()
-    sys.exit(1)
+  def close_test_log(self):
+    """Close per-test logfile, leaving only the null handler."""
+    if self.test_handler:
+      self.test.info('Closing logfile' % filename)
+      self.test.removeHandler(self.test_handler)
+    self.test_handler = None
+    self.test_file.close()
+  
+  def ddebug(self, msg, *args, **kwargs):
+    """Log with priority 5 (normal DEBUG is 10)"""
+    self.log(5, msg, *args, **kwargs)