1#!/usr/bin/env python3
2#
3#   Copyright 2016 - The Android Open Source Project
4#
5#   Licensed under the Apache License, Version 2.0 (the "License");
6#   you may not use this file except in compliance with the License.
7#   You may obtain a copy of the License at
8#
9#       http://www.apache.org/licenses/LICENSE-2.0
10#
11#   Unless required by applicable law or agreed to in writing, software
12#   distributed under the License is distributed on an "AS IS" BASIS,
13#   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14#   See the License for the specific language governing permissions and
15#   limitations under the License.
16
17from __future__ import print_function
18
19import datetime
20import logging
21import os
22import re
23
24from copy import copy
25
26from acts import tracelogger
27from acts.libs.logging import log_stream
28from acts.libs.logging.log_stream import LogStyles
29
30log_line_format = "%(asctime)s.%(msecs).03d %(levelname)s %(message)s"
31# The micro seconds are added by the format string above,
32# so the time format does not include ms.
33log_line_time_format = "%Y-%m-%d %H:%M:%S"
34log_line_timestamp_len = 23
35
36logline_timestamp_re = re.compile("\d\d\d\d-\d\d-\d\d \d\d:\d\d:\d\d.\d\d\d")
37
38
39# yapf: disable
40class Style:
41    RESET  = '\033[0m'
42    BRIGHT = '\033[1m'
43    DIM    = '\033[2m'
44    NORMAL = '\033[22m'
45
46
47class Fore:
48    BLACK   = '\033[30m'
49    RED     = '\033[31m'
50    GREEN   = '\033[32m'
51    YELLOW  = '\033[33m'
52    BLUE    = '\033[34m'
53    MAGENTA = '\033[35m'
54    CYAN    = '\033[36m'
55    WHITE   = '\033[37m'
56    RESET   = '\033[39m'
57
58
59class Back:
60    BLACK   = '\033[40m'
61    RED     = '\033[41m'
62    GREEN   = '\033[42m'
63    YELLOW  = '\033[43m'
64    BLUE    = '\033[44m'
65    MAGENTA = '\033[45m'
66    CYAN    = '\033[46m'
67    WHITE   = '\033[47m'
68    RESET   = '\033[49m'
69
70
71LOG_LEVELS = {
72  'DEBUG':     {'level': 10, 'style': Fore.GREEN + Style.BRIGHT},
73  'CASE':      {'level': 11, 'style': Back.BLUE + Fore.WHITE + Style.BRIGHT},
74  'SUITE':     {'level': 12, 'style': Back.MAGENTA + Fore.WHITE + Style.BRIGHT},
75  'INFO':      {'level': 20, 'style': Style.NORMAL},
76  'STEP':      {'level': 15, 'style': Fore.WHITE + Style.BRIGHT},
77  'WARNING':   {'level': 30, 'style': Fore.YELLOW + Style.BRIGHT},
78  'ERROR':     {'level': 40, 'style': Fore.RED + Style.BRIGHT},
79  'EXCEPTION': {'level': 45, 'style': Back.RED + Fore.WHITE + Style.BRIGHT},
80  'DEVICE':    {'level': 51, 'style': Fore.CYAN + Style.BRIGHT},
81}
82# yapf: enable
83
84
85class ColoredLogFormatter(logging.Formatter):
86    def format(self, record):
87        colored_record = copy(record)
88        level_name = colored_record.levelname
89        style = LOG_LEVELS[level_name]['style']
90        formatted_level_name = '%s%s%s' % (style, level_name, Style.RESET)
91        colored_record.levelname = formatted_level_name
92        return super().format(colored_record)
93
94
95def _parse_logline_timestamp(t):
96    """Parses a logline timestamp into a tuple.
97
98    Args:
99        t: Timestamp in logline format.
100
101    Returns:
102        An iterable of date and time elements in the order of month, day, hour,
103        minute, second, microsecond.
104    """
105    date, time = t.split(' ')
106    year, month, day = date.split('-')
107    h, m, s = time.split(':')
108    s, ms = s.split('.')
109    return year, month, day, h, m, s, ms
110
111
112def is_valid_logline_timestamp(timestamp):
113    if len(timestamp) == log_line_timestamp_len:
114        if logline_timestamp_re.match(timestamp):
115            return True
116    return False
117
118
119def logline_timestamp_comparator(t1, t2):
120    """Comparator for timestamps in logline format.
121
122    Args:
123        t1: Timestamp in logline format.
124        t2: Timestamp in logline format.
125
126    Returns:
127        -1 if t1 < t2; 1 if t1 > t2; 0 if t1 == t2.
128    """
129    dt1 = _parse_logline_timestamp(t1)
130    dt2 = _parse_logline_timestamp(t2)
131    for u1, u2 in zip(dt1, dt2):
132        if u1 < u2:
133            return -1
134        elif u1 > u2:
135            return 1
136    return 0
137
138
139def _get_timestamp(time_format, delta=None):
140    t = datetime.datetime.now()
141    if delta:
142        t = t + datetime.timedelta(seconds=delta)
143    return t.strftime(time_format)[:-3]
144
145
146def epoch_to_log_line_timestamp(epoch_time):
147    """Converts an epoch timestamp in ms to log line timestamp format, which
148    is readable for humans.
149
150    Args:
151        epoch_time: integer, an epoch timestamp in ms.
152
153    Returns:
154        A string that is the corresponding timestamp in log line timestamp
155        format.
156    """
157    s, ms = divmod(epoch_time, 1000)
158    d = datetime.datetime.fromtimestamp(s)
159    return d.strftime("%Y-%m-%d %H:%M:%S.") + str(ms)
160
161
162def get_log_line_timestamp(delta=None):
163    """Returns a timestamp in the format used by log lines.
164
165    Default is current time. If a delta is set, the return value will be
166    the current time offset by delta seconds.
167
168    Args:
169        delta: Number of seconds to offset from current time; can be negative.
170
171    Returns:
172        A timestamp in log line format with an offset.
173    """
174    return _get_timestamp("%Y-%m-%d %H:%M:%S.%f", delta)
175
176
177def get_log_file_timestamp(delta=None):
178    """Returns a timestamp in the format used for log file names.
179
180    Default is current time. If a delta is set, the return value will be
181    the current time offset by delta seconds.
182
183    Args:
184        delta: Number of seconds to offset from current time; can be negative.
185
186    Returns:
187        A timestamp in log file name format with an offset.
188    """
189    return _get_timestamp("%Y-%m-%d_%H-%M-%S-%f", delta)
190
191
192def _setup_test_logger(log_path, prefix=None):
193    """Customizes the root logger for a test run.
194
195    The logger object has a stream handler and a file handler. The stream
196    handler logs INFO level to the terminal, the file handler logs DEBUG
197    level to files.
198
199    Args:
200        log_path: Location of the log file.
201        prefix: A prefix for each log line in terminal.
202    """
203    logging.log_path = log_path
204    log_styles = [
205        LogStyles.LOG_INFO + LogStyles.TO_STDOUT,
206        LogStyles.DEFAULT_LEVELS + LogStyles.TESTCASE_LOG
207    ]
208    terminal_format = log_line_format
209    if prefix:
210        terminal_format = "[{}] {}".format(prefix, log_line_format)
211    stream_formatter = ColoredLogFormatter(terminal_format,
212                                           log_line_time_format)
213    file_formatter = logging.Formatter(log_line_format, log_line_time_format)
214    log = log_stream.create_logger('test_run',
215                                   '',
216                                   log_styles=log_styles,
217                                   stream_format=stream_formatter,
218                                   file_format=file_formatter)
219    log.setLevel(logging.DEBUG)
220    _enable_additional_log_levels()
221
222
223def _enable_additional_log_levels():
224    """Enables logging levels used for tracing tests and debugging devices."""
225    for log_type, log_data in LOG_LEVELS.items():
226        logging.addLevelName(log_data['level'], log_type)
227
228
229def kill_test_logger(logger):
230    """Cleans up a test logger object by removing all of its handlers.
231
232    Args:
233        logger: The logging object to clean up.
234    """
235    for h in list(logger.handlers):
236        logger.removeHandler(h)
237        if isinstance(h, logging.FileHandler):
238            h.close()
239
240
241def create_latest_log_alias(actual_path):
242    """Creates a symlink to the latest test run logs.
243
244    Args:
245        actual_path: The source directory where the latest test run's logs are.
246    """
247    link_path = os.path.join(os.path.dirname(actual_path), "latest")
248    if os.path.islink(link_path):
249        os.remove(link_path)
250    os.symlink(actual_path, link_path)
251
252
253def setup_test_logger(log_path, prefix=None):
254    """Customizes the root logger for a test run.
255
256    Args:
257        log_path: Location of the report file.
258        prefix: A prefix for each log line in terminal.
259        filename: Name of the files. The default is the time the objects
260            are requested.
261    """
262    os.makedirs(log_path, exist_ok=True)
263    _setup_test_logger(log_path, prefix)
264    create_latest_log_alias(log_path)
265
266
267def normalize_log_line_timestamp(log_line_timestamp):
268    """Replace special characters in log line timestamp with normal characters.
269
270    Args:
271        log_line_timestamp: A string in the log line timestamp format. Obtained
272            with get_log_line_timestamp.
273
274    Returns:
275        A string representing the same time as input timestamp, but without
276        special characters.
277    """
278    norm_tp = log_line_timestamp.replace(' ', '_')
279    norm_tp = norm_tp.replace(':', '-')
280    return norm_tp
281
282
283class LoggerAdapter(logging.LoggerAdapter):
284    """A LoggerAdapter class that takes in a lambda for transforming logs."""
285    def __init__(self, logging_lambda):
286        self.logging_lambda = logging_lambda
287        super(LoggerAdapter, self).__init__(logging.getLogger(), {})
288
289    def process(self, msg, kwargs):
290        return self.logging_lambda(msg), kwargs
291
292
293def create_logger(logging_lambda=lambda message: message):
294    """Returns a logger with logging defined by a given lambda.
295
296    Args:
297        logging_lambda: A lambda of the form:
298            >>> lambda log_message: return 'string'
299    """
300    return tracelogger.TraceLogger(LoggerAdapter(logging_lambda))
301
302
303def create_tagged_trace_logger(tag=''):
304    """Returns a logger that logs each line with the given prefix.
305
306    Args:
307        tag: The tag of the log line, E.g. if tag == tag123, the output
308            line would be:
309
310            <TESTBED> <TIME> <LOG_LEVEL> [tag123] logged message
311    """
312    def logging_lambda(msg):
313        return '[%s] %s' % (tag, msg)
314
315    return create_logger(logging_lambda)
316