Make use of standard logging library to handle logs

The goal is to provide an easy api to log stuff and a straigthforward way of inspect them. This has been achieved using the standard logging library. The default behaviour is pretty similar to the old one, in the sense that all the the produced logs will be collected in a queue that can be inspected with the curses log viewer (`display_log` command). Moreover the `--logfile` cli option has been added and it can be used to specifya destination file for all the logs in such a way that the same log can be viewed at runtime as well as inspected after a program crash.

The verbosity and the format of the log message is controlled by the already existent `--debug` command line flag:

 - Normal mode:
    A concise log format will be used and only important message will be logged (log level > INFO)

    Example:
    ```
    [INFO] Ranger version 1.7.2
    [INFO] Running on Python 3.5.2 (default, Jun 28 2016, 08:46:01) [GCC 6.1.1 20160602]
    [INFO] Process ID is 1497

    ```

 - Debug mode:
    An extended log format will be used and all the message will be logged.

    Example:
    ```
    23:17:43,719 [ranger.core.main] |INFO| Ranger version 1.7.2
    23:17:43,719 [ranger.core.main] |INFO| Running on Python 3.5.2 (default, Jun 28 2016, 08:46:01) [GCC 6.1.1 20160602]
    23:17:43,719 [ranger.core.main] |INFO| Process ID is 1515
    23:17:43,720 [ranger.core.main] |DEBUG| config dir: '/home/groucho/.config/ranger'
    23:17:43,720 [ranger.core.main] |DEBUG| cache dir: '/home/groucho/.cache/ranger'
    23:17:43,738 [ranger.core.actions] |DEBUG| Sourcing config file '/path/to/ranger/config/rc.conf'
    ```

fixes #713

4 files changed, 102 insertions, 4 deletions

diff --git a/ranger/core/actions.py b/ranger/core/actions.py
index c119c501..6d1824c2 100644
--- a/ranger/core/actions.py
+++ b/ranger/core/actions.py
@@ -869,11 +869,13 @@ class Actions(FileManagerAware, SettingsAware):
             self.notify("Could not find manpage.", bad=True)
 
     def display_log(self):
+        logs = list(self.get_log())
         pager = self.ui.open_pager()
-        if self.log:
-            pager.set_source(["Message Log:"] + list(self.log))
+        if logs:
+            pager.set_source(["Message Log:"] + logs)
         else:
             pager.set_source(["Message Log:", "No messages!"])
+        pager.move(to=100, percentage=True)
 
     def display_file(self):
         if not self.thisfile or not self.thisfile.is_file:
diff --git a/ranger/core/fm.py b/ranger/core/fm.py
index a08de2e1..719479eb 100644
--- a/ranger/core/fm.py
+++ b/ranger/core/fm.py
@@ -5,6 +5,7 @@
 
 from time import time
 from collections import deque
+import logging
 import mimetypes
 import os.path
 import pwd
@@ -27,6 +28,9 @@ from ranger.container.directory import Directory
 from ranger.ext.signals import SignalDispatcher
 from ranger import __version__
 from ranger.core.loader import Loader
+from ranger.ext import logutils
+
+log = logging.getLogger(__name__)
 
 
 class FM(Actions, SignalDispatcher):
@@ -50,7 +54,6 @@ class FM(Actions, SignalDispatcher):
             self.ui = ui
         self.start_paths = paths
         self.directories = dict()
-        self.log = deque(maxlen=1000)
         self.bookmarks = bookmarks
         self.current_tab = 1
         self.tabs = {}
@@ -205,6 +208,15 @@ class FM(Actions, SignalDispatcher):
                 if debug:
                     raise
 
+    def get_log(self):
+        """Return the current log
+
+        The log is returned as a list of string
+        """
+        for log in logutils.log_queue:
+            for line in log.split('\n'):
+                yield line
+
     def _get_image_displayer(self):
         if self.settings.preview_images_method == "w3m":
             return W3MImageDisplayer()
diff --git a/ranger/core/main.py b/ranger/core/main.py
index 341b48e6..d2f5c709 100644
--- a/ranger/core/main.py
+++ b/ranger/core/main.py
@@ -6,6 +6,9 @@
 import os.path
 import sys
 import tempfile
+from logging import getLogger
+
+log = getLogger(__name__)
 
 
 def main():
@@ -15,6 +18,10 @@ def main():
     from ranger.container.settings import Settings
     from ranger.core.shared import FileManagerAware, SettingsAware
     from ranger.core.fm import FM
+    from ranger.ext.logutils import setup_logging
+
+    ranger.arg = arg = parse_arguments()
+    setup_logging(debug=arg.debug, logfile=arg.logfile)
 
     try:
         locale.setlocale(locale.LC_ALL, '')
@@ -31,7 +38,6 @@ def main():
     if 'SHELL' not in os.environ:
         os.environ['SHELL'] = 'sh'
 
-    ranger.arg = arg = parse_arguments()
     if arg.copy_config is not None:
         fm = FM()
         fm.copy_config_files(arg.copy_config)
diff --git a/ranger/ext/logutils.py b/ranger/ext/logutils.py
new file mode 100644
index 00000000..0de6c333
--- /dev/null
+++ b/ranger/ext/logutils.py
@@ -0,0 +1,78 @@
+import logging
+from collections import deque
+
+LOG_FORMAT = "[%(levelname)s] %(message)s"
+LOG_FORMAT_EXT = "%(asctime)s,%(msecs)d [%(name)s] |%(levelname)s| %(message)s"
+LOG_DATA_FORMAT = "%H:%M:%S"
+
+
+class QueueHandler(logging.Handler):
+    """
+    This handler store logs events into a queue.
+    """
+
+    def __init__(self, queue):
+        """
+        Initialize an instance, using the passed queue.
+        """
+        logging.Handler.__init__(self)
+        self.queue = queue
+
+    def enqueue(self, record):
+        """
+        Enqueue a log record.
+        """
+        self.queue.append(record)
+
+    def emit(self, record):
+        self.enqueue(self.format(record))
+
+
+log_queue = deque(maxlen=1000)
+concise_formatter = logging.Formatter(fmt=LOG_FORMAT, datefmt=LOG_DATA_FORMAT)
+extended_formatter = logging.Formatter(fmt=LOG_FORMAT_EXT, datefmt=LOG_DATA_FORMAT)
+
+
+def setup_logging(debug=True, logfile=None):
+    """
+    All the produced logs using the standard logging function
+    will be collected in a queue by the `queue_handler` as well
+    as outputted on the standard error `stderr_handler`.
+
+    The verbosity and the format of the log message is
+    controlled by the `debug` parameter
+
+     - debug=False:
+            a concise log format will be used, debug messsages will be discarded
+            and only important message will be passed to the `stderr_handler`
+
+     - debug=True:
+            an extended log format will be used, all messages will be processed
+            by both the handlers
+    """
+    root_logger = logging.getLogger()
+
+    if debug:
+        # print all logging in extended format
+        log_level = logging.DEBUG
+        formatter = extended_formatter
+    else:
+        # print only warning and critical message
+        # in a concise format
+        log_level = logging.INFO
+        formatter = concise_formatter
+
+    handlers = []
+    handlers.append(QueueHandler(log_queue))
+    if logfile:
+        if logfile is '-':
+            handlers.append(logging.StreamHandler())
+        else:
+            handlers.append(logging.FileHandler(logfile))
+
+    for handler in handlers:
+        handler.setLevel(log_level)
+        handler.setFormatter(formatter)
+        root_logger.addHandler(handler)
+
+    root_logger.setLevel(0)