1#!/usr/bin/env python3
2#
3#   Copyright 2018 - 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.
16import logging
17import os
18import sys
19from logging import FileHandler
20from logging import Handler
21from logging import StreamHandler
22from logging.handlers import RotatingFileHandler
23
24from acts import context
25from acts.context import ContextLevel
26from acts.event import event_bus
27from acts.event.decorators import subscribe_static
28
29
30# yapf: disable
31class LogStyles:
32    NONE         = 0x00
33    LOG_DEBUG    = 0x01
34    LOG_INFO     = 0x02
35    LOG_WARNING  = 0x04
36    LOG_ERROR    = 0x08
37    LOG_CRITICAL = 0x10
38
39    DEFAULT_LEVELS = LOG_DEBUG + LOG_INFO + LOG_ERROR
40    ALL_LEVELS = LOG_DEBUG + LOG_INFO + LOG_WARNING + LOG_ERROR + LOG_CRITICAL
41
42    MONOLITH_LOG  = 0x0100
43    TESTCLASS_LOG = 0x0200
44    TESTCASE_LOG  = 0x0400
45    TO_STDOUT     = 0x0800
46    TO_ACTS_LOG   = 0x1000
47    ROTATE_LOGS   = 0x2000
48
49    ALL_FILE_LOGS = MONOLITH_LOG + TESTCLASS_LOG + TESTCASE_LOG
50
51    LEVEL_NAMES = {
52        LOG_DEBUG: 'debug',
53        LOG_INFO: 'info',
54        LOG_WARNING: 'warning',
55        LOG_ERROR: 'error',
56        LOG_CRITICAL: 'critical',
57    }
58
59    LOG_LEVELS = [
60        LOG_DEBUG,
61        LOG_INFO,
62        LOG_WARNING,
63        LOG_ERROR,
64        LOG_CRITICAL,
65    ]
66
67    LOG_LOCATIONS = [
68        TO_STDOUT,
69        TO_ACTS_LOG,
70        MONOLITH_LOG,
71        TESTCLASS_LOG,
72        TESTCASE_LOG
73    ]
74
75    LEVEL_TO_NO = {
76        LOG_DEBUG: logging.DEBUG,
77        LOG_INFO: logging.INFO,
78        LOG_WARNING: logging.WARNING,
79        LOG_ERROR: logging.ERROR,
80        LOG_CRITICAL: logging.CRITICAL,
81    }
82
83    LOCATION_TO_CONTEXT_LEVEL = {
84        MONOLITH_LOG: ContextLevel.ROOT,
85        TESTCLASS_LOG: ContextLevel.TESTCLASS,
86        TESTCASE_LOG: ContextLevel.TESTCASE
87    }
88# yapf: enable
89
90
91_log_streams = dict()
92_null_handler = logging.NullHandler()
93
94
95@subscribe_static(context.NewContextEvent)
96def _update_handlers(event):
97    for log_stream in _log_streams.values():
98        log_stream.update_handlers(event)
99
100
101event_bus.register_subscription(_update_handlers.subscription)
102
103
104def create_logger(name, log_name=None, base_path='', subcontext='',
105                  log_styles=LogStyles.NONE, stream_format=None,
106                  file_format=None):
107    """Creates a Python Logger object with the given attributes.
108
109    Creation through this method will automatically manage the logger in the
110    background for test-related events, such as TestCaseBegin and TestCaseEnd
111    Events.
112
113    Args:
114        name: The name of the LogStream. Used as the file name prefix.
115        log_name: The name of the underlying logger. Use LogStream name as
116            default.
117        base_path: The base path used by the logger.
118        subcontext: Location of logs relative to the test context path.
119        log_styles: An integer or array of integers that are the sum of
120            corresponding flag values in LogStyles. Examples include:
121
122            >>> LogStyles.LOG_INFO + LogStyles.TESTCASE_LOG
123
124            >>> LogStyles.ALL_LEVELS + LogStyles.MONOLITH_LOG
125
126            >>> [LogStyles.DEFAULT_LEVELS + LogStyles.MONOLITH_LOG]
127            >>>  LogStyles.LOG_ERROR + LogStyles.TO_ACTS_LOG]
128        stream_format: Format used for log output to stream
129        file_format: Format used for log output to files
130    """
131    if name in _log_streams:
132        _log_streams[name].cleanup()
133    log_stream = _LogStream(name, log_name, base_path, subcontext, log_styles,
134                            stream_format, file_format)
135    _set_logger(log_stream)
136    return log_stream.logger
137
138
139def _set_logger(log_stream):
140    _log_streams[log_stream.name] = log_stream
141    return log_stream
142
143
144class AlsoToLogHandler(Handler):
145    """Logs a message at a given level also to another logger.
146
147    Used for logging messages at a high enough level to the main log, or another
148    logger.
149    """
150
151    def __init__(self, to_logger=None, *args, **kwargs):
152        super().__init__(*args, **kwargs)
153        self._log = logging.getLogger(to_logger)
154
155    def emit(self, record):
156        self._log.log(record.levelno, record.getMessage())
157
158
159class MovableFileHandler(FileHandler):
160    """FileHandler implementation that allows the output file to be changed
161    during operation.
162    """
163    def set_file(self, file_name):
164        """Set the target output file to file_name.
165
166        Args:
167            file_name: path to the new output file
168        """
169        self.baseFilename = os.path.abspath(file_name)
170        if self.stream is not None:
171            new_stream = self._open()
172            # An atomic operation redirects the output and closes the old file
173            os.dup2(new_stream.fileno(), self.stream.fileno())
174            self.stream = new_stream
175
176
177class MovableRotatingFileHandler(RotatingFileHandler):
178    """RotatingFileHandler implementation that allows the output file to be
179    changed during operation. Rotated files will automatically adopt the newest
180    output path.
181    """
182    set_file = MovableFileHandler.set_file
183
184
185class InvalidStyleSetError(Exception):
186    """Raised when the given LogStyles are an invalid set."""
187
188
189class _LogStream(object):
190    """A class that sets up a logging.Logger object.
191
192    The LogStream class creates a logging.Logger object. LogStream is also
193    responsible for managing the logger when events take place, such as
194    TestCaseEndedEvents and TestCaseBeginEvents.
195
196    Attributes:
197        name: The name of the LogStream.
198        logger: The logger created by this LogStream.
199        base_path: The base path used by the logger. Use logging.log_path
200            as default.
201        subcontext: Location of logs relative to the test context path.
202        stream_format: Format used for log output to stream
203        file_format: Format used for log output to files
204    """
205
206    def __init__(self, name, log_name=None, base_path='', subcontext='',
207                 log_styles=LogStyles.NONE, stream_format=None,
208                 file_format=None):
209        """Creates a LogStream.
210
211        Args:
212            name: The name of the LogStream. Used as the file name prefix.
213            log_name: The name of the underlying logger. Use LogStream name
214                as default.
215            base_path: The base path used by the logger. Use logging.log_path
216                as default.
217            subcontext: Location of logs relative to the test context path.
218            log_styles: An integer or array of integers that are the sum of
219                corresponding flag values in LogStyles. Examples include:
220
221                >>> LogStyles.LOG_INFO + LogStyles.TESTCASE_LOG
222
223                >>> LogStyles.ALL_LEVELS + LogStyles.MONOLITH_LOG
224
225                >>> [LogStyles.DEFAULT_LEVELS + LogStyles.MONOLITH_LOG]
226                >>>  LogStyles.LOG_ERROR + LogStyles.TO_ACTS_LOG]
227            stream_format: Format used for log output to stream
228            file_format: Format used for log output to files
229        """
230        self.name = name
231        if log_name is not None:
232            self.logger = logging.getLogger(log_name)
233        else:
234            self.logger = logging.getLogger(name)
235        # Add a NullHandler to suppress unwanted console output
236        self.logger.addHandler(_null_handler)
237        self.logger.propagate = False
238        self.base_path = base_path or logging.log_path
239        self.subcontext = subcontext
240        context.TestContext.add_base_output_path(self.logger.name, self.base_path)
241        context.TestContext.add_subcontext(self.logger.name, self.subcontext)
242        self.stream_format = stream_format
243        self.file_format = file_format
244        self._testclass_handlers = []
245        self._testcase_handlers = []
246        if not isinstance(log_styles, list):
247            log_styles = [log_styles]
248        self.__validate_styles(log_styles)
249        for log_style in log_styles:
250            self.__handle_style(log_style)
251
252    @staticmethod
253    def __validate_styles(_log_styles_list):
254        """Determines if the given list of styles is valid.
255
256        Terminology:
257            Log-level: any of [DEBUG, INFO, WARNING, ERROR, CRITICAL].
258            Log Location: any of [MONOLITH_LOG, TESTCLASS_LOG,
259                                  TESTCASE_LOG, TO_STDOUT, TO_ACTS_LOG].
260
261        Styles are invalid when any of the below criteria are met:
262            A log-level is not set within an element of the list.
263            A log location is not set within an element of the list.
264            A log-level, log location pair appears twice within the list.
265            A log-level has both TESTCLASS and TESTCASE locations set
266                within the list.
267            ROTATE_LOGS is set without MONOLITH_LOG,
268                TESTCLASS_LOG, or TESTCASE_LOG.
269
270        Raises:
271            InvalidStyleSetError if the given style cannot be achieved.
272        """
273
274        def invalid_style_error(message):
275            raise InvalidStyleSetError('{LogStyle Set: %s} %s' %
276                                       (_log_styles_list, message))
277
278        # Store the log locations that have already been set per level.
279        levels_dict = {}
280        for log_style in _log_styles_list:
281            for level in LogStyles.LOG_LEVELS:
282                if log_style & level:
283                    levels_dict[level] = levels_dict.get(level, LogStyles.NONE)
284                    # Check that a log-level, log location pair has not yet
285                    # been set.
286                    for log_location in LogStyles.LOG_LOCATIONS:
287                        if log_style & log_location:
288                            if log_location & levels_dict[level]:
289                                invalid_style_error(
290                                    'The log location %s for log level %s has '
291                                    'been set multiple times' %
292                                    (log_location, level))
293                            else:
294                                levels_dict[level] |= log_location
295                    # Check that for a given log-level, not more than one
296                    # of MONOLITH_LOG, TESTCLASS_LOG, TESTCASE_LOG is set.
297                    locations = levels_dict[level] & LogStyles.ALL_FILE_LOGS
298                    valid_locations = [
299                        LogStyles.TESTCASE_LOG, LogStyles.TESTCLASS_LOG,
300                        LogStyles.MONOLITH_LOG, LogStyles.NONE]
301                    if locations not in valid_locations:
302                        invalid_style_error(
303                            'More than one of MONOLITH_LOG, TESTCLASS_LOG, '
304                            'TESTCASE_LOG is set for log level %s.' % level)
305            if log_style & LogStyles.ALL_LEVELS == 0:
306                invalid_style_error('LogStyle %s needs to set a log '
307                                    'level.' % log_style)
308            if log_style & ~LogStyles.ALL_LEVELS == 0:
309                invalid_style_error('LogStyle %s needs to set a log '
310                                    'location.' % log_style)
311            if log_style & LogStyles.ROTATE_LOGS and not log_style & (
312                    LogStyles.MONOLITH_LOG | LogStyles.TESTCLASS_LOG |
313                    LogStyles.TESTCASE_LOG):
314                invalid_style_error('LogStyle %s has ROTATE_LOGS set, but does '
315                                    'not specify a log type.' % log_style)
316
317    @staticmethod
318    def __create_rotating_file_handler(filename):
319        """Generates a callable to create an appropriate RotatingFileHandler."""
320        # Magic number explanation: 10485760 == 10MB
321        return MovableRotatingFileHandler(filename, maxBytes=10485760,
322                                          backupCount=5)
323
324    @staticmethod
325    def __get_file_handler_creator(log_style):
326        """Gets the callable to create the correct FileLogHandler."""
327        create_file_handler = MovableFileHandler
328        if log_style & LogStyles.ROTATE_LOGS:
329            create_file_handler = _LogStream.__create_rotating_file_handler
330        return create_file_handler
331
332    @staticmethod
333    def __get_lowest_log_level(log_style):
334        """Returns the lowest log level's LogStyle for the given log_style."""
335        for log_level in LogStyles.LOG_LEVELS:
336            if log_level & log_style:
337                return log_level
338        return LogStyles.NONE
339
340    def __get_current_output_dir(self, depth=ContextLevel.TESTCASE):
341        """Gets the current output directory from the context system. Make the
342        directory if it doesn't exist.
343
344        Args:
345            depth: The desired level of the output directory. For example,
346                the TESTCLASS level would yield the directory associated with
347                the current test class context, even if the test is currently
348                within a test case.
349        """
350        curr_context = context.get_current_context(depth)
351        return curr_context.get_full_output_path(self.logger.name)
352
353    def __create_handler(self, creator, level, location):
354        """Creates the FileHandler.
355
356        Args:
357            creator: The callable that creates the FileHandler
358            level: The logging level (INFO, DEBUG, etc.) for this handler.
359            location: The log location (MONOLITH, TESTCLASS, TESTCASE) for this
360                handler.
361
362        Returns: A FileHandler
363        """
364        directory = self.__get_current_output_dir(
365            LogStyles.LOCATION_TO_CONTEXT_LEVEL[location])
366        base_name = '%s_%s.txt' % (self.name, LogStyles.LEVEL_NAMES[level])
367        handler = creator(os.path.join(directory, base_name))
368        handler.setLevel(LogStyles.LEVEL_TO_NO[level])
369        if self.file_format:
370            handler.setFormatter(self.file_format)
371        return handler
372
373    def __handle_style(self, log_style):
374        """Creates the handlers described in the given log_style."""
375        handler_creator = self.__get_file_handler_creator(log_style)
376
377        # Handle streaming logs to STDOUT or the ACTS Logger
378        if log_style & (LogStyles.TO_ACTS_LOG | LogStyles.TO_STDOUT):
379            lowest_log_level = self.__get_lowest_log_level(log_style)
380
381            if log_style & LogStyles.TO_ACTS_LOG:
382                handler = AlsoToLogHandler()
383            else:  # LogStyles.TO_STDOUT:
384                handler = StreamHandler(sys.stdout)
385                if self.stream_format:
386                    handler.setFormatter(self.stream_format)
387
388            handler.setLevel(LogStyles.LEVEL_TO_NO[lowest_log_level])
389            self.logger.addHandler(handler)
390
391        # Handle streaming logs to log-level files
392        for log_level in LogStyles.LOG_LEVELS:
393            log_location = log_style & LogStyles.ALL_FILE_LOGS
394            if not (log_style & log_level and log_location):
395                continue
396
397            handler = self.__create_handler(
398                handler_creator, log_level, log_location)
399            self.logger.addHandler(handler)
400
401            if log_style & LogStyles.TESTCLASS_LOG:
402                self._testclass_handlers.append(handler)
403            if log_style & LogStyles.TESTCASE_LOG:
404                self._testcase_handlers.append(handler)
405
406    def __remove_handler(self, handler):
407        """Removes a handler from the logger, unless it's a NullHandler."""
408        if handler is not _null_handler:
409            handler.close()
410            self.logger.removeHandler(handler)
411
412    def update_handlers(self, event):
413        """Update the output file paths for log handlers upon a change in
414        the test context.
415
416        Args:
417            event: An instance of NewContextEvent.
418        """
419        handlers = []
420        if isinstance(event, context.NewTestClassContextEvent):
421            handlers = self._testclass_handlers + self._testcase_handlers
422        if isinstance(event, context.NewTestCaseContextEvent):
423            handlers = self._testcase_handlers
424
425        if not handlers:
426            return
427        new_dir = self.__get_current_output_dir()
428        for handler in handlers:
429            filename = os.path.basename(handler.baseFilename)
430            handler.set_file(os.path.join(new_dir, filename))
431
432    def cleanup(self):
433        """Removes all LogHandlers from the logger."""
434        for handler in self.logger.handlers:
435            self.__remove_handler(handler)
436