1#
2# Copyright (C) 2016 The Android Open Source Project
3#
4# Licensed under the Apache License, Version 2.0 (the "License");
5# you may not use this file except in compliance with the License.
6# You may obtain a copy of the License at
7#
8#      http://www.apache.org/licenses/LICENSE-2.0
9#
10# Unless required by applicable law or agreed to in writing, software
11# distributed under the License is distributed on an "AS IS" BASIS,
12# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13# See the License for the specific language governing permissions and
14# limitations under the License.
15#
16
17from __future__ import print_function
18
19import datetime
20import logging
21import os
22import re
23import sys
24
25from vts.runners.host import utils
26
27log_line_format = "%(asctime)s.%(msecs).03d %(levelname)s %(message)s"
28# The micro seconds are added by the format string above,
29# so the time format does not include ms.
30log_line_time_format = "%m-%d %H:%M:%S"
31log_line_timestamp_len = 18
32
33logline_timestamp_re = re.compile("\d\d-\d\d \d\d:\d\d:\d\d.\d\d\d")
34
35log_severity_map = {
36    "ERROR": logging.ERROR,
37    "WARNING": logging.WARNING,
38    "INFO": logging.INFO,
39    "DEBUG": logging.DEBUG,
40}
41
42# Directory name in the log path in which files will be included in TradeFed output
43PYTHON_CUSTOM_OUTPUT = 'custom_output_files'
44
45def _parse_logline_timestamp(t):
46    """Parses a logline timestamp into a tuple.
47
48    Args:
49        t: Timestamp in logline format.
50
51    Returns:
52        An iterable of date and time elements in the order of month, day, hour,
53        minute, second, microsecond.
54    """
55    date, time = t.split(' ')
56    month, day = date.split('-')
57    h, m, s = time.split(':')
58    s, ms = s.split('.')
59    return (month, day, h, m, s, ms)
60
61
62def isValidLogLineTimestamp(timestamp):
63    if len(timestamp) == log_line_timestamp_len:
64        if logline_timestamp_re.match(timestamp):
65            return True
66    return False
67
68
69def logLineTimestampComparator(t1, t2):
70    """Comparator for timestamps in logline format.
71
72    Args:
73        t1: Timestamp in logline format.
74        t2: Timestamp in logline format.
75
76    Returns:
77        -1 if t1 < t2; 1 if t1 > t2; 0 if t1 == t2.
78    """
79    dt1 = _parse_logline_timestamp(t1)
80    dt2 = _parse_logline_timestamp(t2)
81    for u1, u2 in zip(dt1, dt2):
82        if u1 < u2:
83            return -1
84        elif u1 > u2:
85            return 1
86    return 0
87
88
89def _get_timestamp(time_format, delta=None):
90    t = datetime.datetime.now()
91    if delta:
92        t = t + datetime.timedelta(seconds=delta)
93    return t.strftime(time_format)[:-3]
94
95
96def epochToLogLineTimestamp(epoch_time):
97    d = datetime.datetime.fromtimestamp(epoch_time / 1000)
98    return d.strftime("%m-%d %H:%M:%S.%f")[:-3]
99
100
101def getLogLineTimestamp(delta=None):
102    """Returns a timestamp in the format used by log lines.
103
104    Default is current time. If a delta is set, the return value will be
105    the current time offset by delta seconds.
106
107    Args:
108        delta: Number of seconds to offset from current time; can be negative.
109
110    Returns:
111        A timestamp in log line format with an offset.
112    """
113    return _get_timestamp("%m-%d %H:%M:%S.%f", delta)
114
115
116def getLogFileTimestamp(delta=None):
117    """Returns a timestamp in the format used for log file names.
118
119    Default is current time. If a delta is set, the return value will be
120    the current time offset by delta seconds.
121
122    Args:
123        delta: Number of seconds to offset from current time; can be negative.
124
125    Returns:
126        A timestamp in log filen name format with an offset.
127    """
128    return _get_timestamp("%m-%d-%Y_%H-%M-%S-%f", delta)
129
130
131def _initiateTestLogger(log_path, prefix=None, filename=None, log_severity="INFO"):
132    """Customizes the root logger for a test run.
133
134    The logger object has a stream handler and a file handler. Both handler logs data
135    according to the log severty level.
136
137    Args:
138        log_path: Location of the log file.
139        prefix: A prefix for each log line in terminal.
140        filename: Name of the log file. The default is the time the logger
141                  is requested.
142        log_severity: string, set the log severity level, default is INFO.
143                      This value affects console stream log handler and the python runner
144                      part of TradeFed host_log.
145    """
146    log = logging.getLogger()
147    # Clean up any remaining handlers.
148    killTestLogger(log)
149    log.propagate = False
150
151    log.setLevel(logging.DEBUG)
152
153    # Log into stream
154    terminal_format = log_line_format
155    if prefix:
156        terminal_format = "[{}] {}".format(prefix, log_line_format)
157    c_formatter = logging.Formatter(terminal_format, log_line_time_format)
158    ch = logging.StreamHandler(sys.stdout)
159    ch.setFormatter(c_formatter)
160    ch.setLevel(log_severity_map.get(log_severity, logging.INFO))
161    log.addHandler(ch)
162
163    # Log everything to file
164    f_formatter = logging.Formatter(log_line_format, log_line_time_format)
165
166    # All the logs of this test class go into one directory
167    if filename is None:
168        filename = getLogFileTimestamp()
169        utils.create_dir(log_path)
170
171    default_log_levels = ('ERROR', 'INFO', 'DEBUG')
172    for level in default_log_levels:
173        idx = filename.rfind('.')
174        if idx < 0:
175            idx = len(filename)
176        addLogFile(log_path=log_path,
177                   filename=filename[:idx] + '_' + level + filename[idx:],
178                   log_severity=level)
179
180    log.log_path = log_path
181    logging.log_path = log_path
182
183
184def killTestLogger(logger):
185    """Cleans up the handlers attached to a test logger object.
186
187    Args:
188        logger: The logging object to clean up.
189    """
190    for h in list(logger.handlers):
191        if isinstance(h, logging.FileHandler):
192            h.close()
193        logger.removeHandler(h)
194
195
196def isSymlinkSupported():
197    """Checks whether the OS supports symbolic link.
198
199    Returns:
200        A boolean representing whether the OS supports symbolic link.
201    """
202    return hasattr(os, "symlink")
203
204
205def createLatestLogAlias(actual_path):
206    """Creates a symlink to the latest test run logs.
207
208    Args:
209        actual_path: The source directory where the latest test run's logs are.
210    """
211    link_path = os.path.join(os.path.dirname(actual_path), "latest")
212    if os.path.islink(link_path):
213        os.remove(link_path)
214    os.symlink(actual_path, link_path)
215
216
217def setupTestLogger(log_path,
218                    prefix=None,
219                    filename=None,
220                    log_severity="INFO",
221                    create_symlink=True):
222    """Customizes the root logger for a test run.
223
224    Args:
225        log_path: Location of the report file.
226        prefix: A prefix for each log line in terminal.
227        filename: Name of the files. The default is the time the objects
228                  are requested.
229        create_symlink: bool. determines whether to create the symlink or not.
230                        set to True as default.
231
232    Returns:
233        A string, abs path to the created log file.
234    """
235    if filename is None:
236        filename = getLogFileTimestamp()
237    utils.create_dir(log_path)
238    logger = _initiateTestLogger(log_path, prefix, filename, log_severity)
239    if create_symlink and isSymlinkSupported():
240        createLatestLogAlias(log_path)
241    return os.path.join(log_path, filename)
242
243
244def addLogFile(log_path, filename=None, log_severity="INFO"):
245    """Creates a log file and adds the handler to the root logger.
246
247    Args:
248        log_path: Location of the report file.
249        filename: Name of the log file. The default is the time the logger
250                  is requested.
251
252    Returns:
253        A string, abs path to the created log file.
254        logging.FileHandler instance which is added to the logger.
255    """
256    if filename is None:
257        filename = getLogFileTimestamp()
258    f_formatter = logging.Formatter(log_line_format, log_line_time_format)
259    fh = logging.FileHandler(os.path.join(log_path, filename))
260    fh.setFormatter(f_formatter)
261    fh.setLevel(log_severity_map.get(log_severity, logging.INFO))
262    logging.getLogger().addHandler(fh)
263    return os.path.join(log_path, filename), fh
264
265
266def normalizeLogLineTimestamp(log_line_timestamp):
267    """Replace special characters in log line timestamp with normal characters.
268
269    Args:
270        log_line_timestamp: A string in the log line timestamp format. Obtained
271            with getLogLineTimestamp.
272
273    Returns:
274        A string representing the same time as input timestamp, but without
275        special characters.
276    """
277    norm_tp = log_line_timestamp.replace(' ', '_')
278    norm_tp = norm_tp.replace(':', '-')
279    return norm_tp
280
281
282class LoggerProxy(object):
283    """This class is for situations where a logger may or may not exist.
284
285    e.g. In controller classes, sometimes we don't have a logger to pass in,
286    like during a quick try in python console. In these cases, we don't want to
287    crash on the log lines because logger is None, so we should set self.log to
288    an object of this class in the controller classes, instead of the actual
289    logger object.
290    """
291
292    def __init__(self, logger=None):
293        self.log = logger
294
295    @property
296    def log_path(self):
297        if self.log:
298            return self.log.log_path
299        return "/tmp/logs"
300
301    def __getattr__(self, name):
302        def log_call(*args):
303            if self.log:
304                return getattr(self.log, name)(*args)
305            print(*args)
306
307        return log_call
308