1# emacs: -*- mode: python; py-indent-offset: 4; tab-width: 4; indent-tabs-mode: nil -*-
2# ex: set sts=4 ts=4 sw=4 noet:
3# ## ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ##
4#
5#   See COPYING file distributed along with the duecredit package for the
6#   copyright and license terms.  This file originates from datalad distributed
7#   under MIT license.
8#
9# ## ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ### ##
10
11import logging, os, sys, platform
12import logging.handlers
13
14from .utils import is_interactive
15
16__all__ = ['ColorFormatter', 'log']
17
18# Snippets from traceback borrowed from PyMVPA upstream/2.4.0-39-g69ad545  MIT license
19
20import traceback
21import re
22from os.path import basename, dirname
23
24def mbasename(s):
25    """Custom function to include directory name if filename is too common
26
27    Also strip .py at the end
28    """
29    base = basename(s)
30    if base.endswith('.py'):
31        base = base[:-3]
32    if base in set(['base', '__init__']):
33        base = basename(dirname(s)) + '.' + base
34    return base
35
36class TraceBack(object):
37    """Customized traceback to be included in debug messages
38    """
39
40    def __init__(self, collide=False):
41        """Initialize TraceBack metric
42
43        Parameters
44        ----------
45        collide : bool
46          if True then prefix common with previous invocation gets
47          replaced with ...
48        """
49        self.__prev = ""
50        self.__collide = collide
51
52    def __call__(self):
53        ftb = traceback.extract_stack(limit=100)[:-2]
54        entries = [[mbasename(x[0]), str(x[1])] for x in ftb if mbasename(x[0]) != 'logging.__init__']
55        entries = [ e for e in entries if e[0] != 'unittest' ]
56
57        # lets make it more concise
58        entries_out = [entries[0]]
59        for entry in entries[1:]:
60            if entry[0] == entries_out[-1][0]:
61                entries_out[-1][1] += ',%s' % entry[1]
62            else:
63                entries_out.append(entry)
64        sftb = '>'.join(['%s:%s' % (mbasename(x[0]),
65                                    x[1]) for x in entries_out])
66        if self.__collide:
67            # lets remove part which is common with previous invocation
68            prev_next = sftb
69            common_prefix = os.path.commonprefix((self.__prev, sftb))
70            common_prefix2 = re.sub('>[^>]*$', '', common_prefix)
71
72            if common_prefix2 != "":
73                sftb = '...' + sftb[len(common_prefix2):]
74            self.__prev = prev_next
75
76        return sftb
77
78
79# Recipe from http://stackoverflow.com/questions/384076/how-can-i-color-python-logging-output
80# by Brandon Thomson
81# Adjusted for automagic determination either coloring is needed and
82# prefixing of multiline log lines
83class ColorFormatter(logging.Formatter):
84
85    BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = range(8)
86
87    RESET_SEQ = "\033[0m"
88    COLOR_SEQ = "\033[1;%dm"
89    BOLD_SEQ = "\033[1m"
90
91    COLORS = {
92      'WARNING': YELLOW,
93      'INFO': WHITE,
94      'DEBUG': BLUE,
95      'CRITICAL': YELLOW,
96      'ERROR': RED
97    }
98
99    def __init__(self, use_color=None, log_name=False):
100        if use_color is None:
101            # if 'auto' - use color only if all streams are tty
102            use_color = is_interactive()
103        self.use_color = use_color and platform.system() != 'Windows'  # don't use color on windows
104        msg = self.formatter_msg(self._get_format(log_name), self.use_color)
105        self._tb = TraceBack(collide=os.environ.get('DUECREDIT_LOGTRACEBACK', '') == 'collide') \
106            if os.environ.get('DUECREDIT_LOGTRACEBACK', False) else None
107        logging.Formatter.__init__(self, msg)
108
109    def _get_format(self, log_name=False):
110        return ("$BOLD%(asctime)-15s$RESET "
111                + ("%(name)-15s " if log_name else "")
112                + "[%(levelname)s] "
113                "%(message)s "
114                "($BOLD%(filename)s$RESET:%(lineno)d)")
115
116    def formatter_msg(self, fmt, use_color=False):
117        if use_color:
118            fmt = fmt.replace("$RESET", self.RESET_SEQ).replace("$BOLD", self.BOLD_SEQ)
119        else:
120            fmt = fmt.replace("$RESET", "").replace("$BOLD", "")
121        return fmt
122
123    def format(self, record):
124        if record.msg.startswith('| '):
125            # If we already log smth which supposed to go without formatting, like
126            # output for running a command, just return the message and be done
127            return record.msg
128
129        levelname = record.levelname
130        if self.use_color and levelname in self.COLORS:
131            fore_color = 30 + self.COLORS[levelname]
132            levelname_color = self.COLOR_SEQ % fore_color + "%-7s" % levelname + self.RESET_SEQ
133            record.levelname = levelname_color
134        record.msg = record.msg.replace("\n", "\n| ")
135        if self._tb:
136            record.msg = self._tb() + "  " + record.msg
137
138        return logging.Formatter.format(self, record)
139
140
141class LoggerHelper(object):
142    """Helper to establish and control a Logger"""
143
144    def __init__(self, name='duecredit'):
145        self.name = name
146        self.lgr = logging.getLogger(name)
147
148    def _get_environ(self, var, default=None):
149        return os.environ.get(self.name.upper() + '_%s' % var.upper(), default)
150
151    def set_level(self, level=None, default='WARNING'):
152        """Helper to set loglevel for an arbitrary logger
153
154        By default operates for 'duecredit'.
155        TODO: deduce name from upper module name so it could be reused without changes
156        """
157        if level is None:
158            # see if nothing in the environment
159            level = self._get_environ('LOGLEVEL')
160        if level is None:
161            level = default
162
163        try:
164            # it might be a string which still represents an int
165            log_level = int(level)
166        except ValueError:
167            # or a string which corresponds to a constant;)
168            log_level = getattr(logging, level.upper())
169
170        self.lgr.setLevel(log_level)
171
172
173    def get_initialized_logger(self, logtarget=None):
174        """Initialize and return the logger
175
176        Parameters
177        ----------
178        target: string, optional
179          Which log target to request logger for
180        logtarget: { 'stdout', 'stderr', str }, optional
181          Where to direct the logs.  stdout and stderr stand for standard streams.
182          Any other string is considered a filename.  Multiple entries could be
183          specified comma-separated
184
185        Returns
186        -------
187        logging.Logger
188        """
189        # By default mimic previously talkative behavior
190        logtarget = self._get_environ('LOGTARGET', logtarget or 'stdout')
191
192        # Allow for multiple handlers being specified, comma-separated
193        if ',' in logtarget:
194            for handler_ in logtarget.split(','):
195                self.get_initialized_logger(logtarget=handler_)
196            return self.lgr
197
198        if logtarget.lower() in ('stdout', 'stderr') :
199            loghandler = logging.StreamHandler(getattr(sys, logtarget.lower()))
200            use_color = is_interactive()  # explicitly decide here
201        else:
202            # must be a simple filename
203            # Use RotatingFileHandler for possible future parametrization to keep
204            # log succinct and rotating
205            loghandler = logging.handlers.RotatingFileHandler(logtarget)
206            use_color = False
207            # I had decided not to guard this call and just raise exception to go
208            # out happen that specified file location is not writable etc.
209        # But now improve with colors and useful information such as time
210        loghandler.setFormatter(
211            ColorFormatter(use_color=use_color,
212                           log_name=self._get_environ("LOGNAME", False)))
213        #logging.Formatter('%(asctime)-15s %(levelname)-6s %(message)s'))
214        self.lgr.addHandler(loghandler)
215
216        self.set_level()  # set default logging level
217        return self.lgr
218
219lgr = LoggerHelper().get_initialized_logger()
220
221