|
1
|
|
|
"""Handle logs displayed by Kytos SDN Platform.""" |
|
2
|
1 |
|
import inspect |
|
3
|
1 |
|
import logging |
|
4
|
1 |
|
import re |
|
5
|
1 |
|
from configparser import RawConfigParser |
|
6
|
|
|
# noqa so it does not conflict with grouped imports |
|
7
|
|
|
# pylint: disable=ungrouped-imports |
|
8
|
1 |
|
from logging import Formatter, config, getLogger |
|
9
|
|
|
# pylint: enable=ungrouped-imports |
|
10
|
1 |
|
from pathlib import Path |
|
11
|
|
|
|
|
12
|
1 |
|
from kytos.core.websocket import WebSocketHandler |
|
13
|
|
|
|
|
14
|
1 |
|
__all__ = ('LogManager', 'NAppLog') |
|
15
|
1 |
|
LOG = getLogger(__name__) |
|
16
|
|
|
|
|
17
|
|
|
|
|
18
|
1 |
|
class LogManager: |
|
19
|
|
|
"""Manage handlers for all loggers.""" |
|
20
|
|
|
|
|
21
|
1 |
|
_PARSER = RawConfigParser() |
|
22
|
1 |
|
_DEFAULT_FMT = 'formatter_console' |
|
23
|
|
|
|
|
24
|
1 |
|
@classmethod |
|
25
|
1 |
|
def load_config_file(cls, config_file, debug='False'): |
|
26
|
|
|
"""Load log configuration file. |
|
27
|
|
|
|
|
28
|
|
|
Check whether file exists and if there's an OSError, try removing |
|
29
|
|
|
syslog handler. |
|
30
|
|
|
|
|
31
|
|
|
Args: |
|
32
|
|
|
config_file (:class:`str`, :class:`pathlib.Path`): |
|
33
|
|
|
Configuration file path. |
|
34
|
|
|
""" |
|
35
|
1 |
|
if Path(config_file).exists(): |
|
36
|
1 |
|
cls._PARSER.read(config_file) |
|
37
|
1 |
|
cls._set_debug_mode(debug) |
|
38
|
1 |
|
cls._use_config_file(config_file) |
|
39
|
|
|
else: |
|
40
|
1 |
|
LOG.warning('Log config file "%s" does not exist. Using default ' |
|
41
|
|
|
'Python logging configuration.', |
|
42
|
|
|
config_file) |
|
43
|
|
|
|
|
44
|
1 |
|
@classmethod |
|
45
|
1 |
|
def _set_debug_mode(cls, debug=False): |
|
46
|
1 |
|
if debug is True: |
|
47
|
1 |
|
cls._PARSER.set('logger_root', 'level', 'DEBUG') |
|
48
|
1 |
|
cls._PARSER.set('logger_kytos', 'level', 'DEBUG') |
|
49
|
1 |
|
cls._PARSER.set('logger_api_server', 'level', 'DEBUG') |
|
50
|
1 |
|
LOG.info('Setting log configuration with debug mode.') |
|
51
|
|
|
|
|
52
|
1 |
|
@classmethod |
|
53
|
1 |
|
def _use_config_file(cls, config_file): |
|
54
|
|
|
"""Use parsed logging configuration.""" |
|
55
|
1 |
|
try: |
|
56
|
1 |
|
config.fileConfig(cls._PARSER, disable_existing_loggers=False) |
|
57
|
1 |
|
LOG.info('Logging config file "%s" loaded successfully.', |
|
58
|
|
|
config_file) |
|
59
|
1 |
|
except OSError: |
|
60
|
1 |
|
cls._catch_config_file_exception(config_file) |
|
61
|
|
|
|
|
62
|
1 |
|
@classmethod |
|
63
|
1 |
|
def _catch_config_file_exception(cls, config_file): |
|
64
|
|
|
"""Try not using syslog handler (for when it is not installed).""" |
|
65
|
1 |
|
if 'handler_syslog' in cls._PARSER: |
|
66
|
1 |
|
LOG.warning('Failed to load "%s". Trying to disable syslog ' |
|
67
|
|
|
'handler.', config_file) |
|
68
|
1 |
|
cls._PARSER.remove_section('handler_syslog') |
|
69
|
1 |
|
cls._use_config_file(config_file) |
|
70
|
|
|
else: |
|
71
|
1 |
|
LOG.warning('Failed to load "%s". Using default Python ' |
|
72
|
|
|
'logging configuration.', config_file) |
|
73
|
|
|
|
|
74
|
1 |
|
@classmethod |
|
75
|
1 |
|
def enable_websocket(cls, socket): |
|
76
|
|
|
"""Output logs to a web socket. |
|
77
|
|
|
|
|
78
|
|
|
Args: |
|
79
|
|
|
socket: socketio's socket. |
|
80
|
|
|
|
|
81
|
|
|
Returns: |
|
82
|
|
|
logging.StreamHandler: Handler with the socket as stream. |
|
83
|
|
|
|
|
84
|
|
|
""" |
|
85
|
1 |
|
handler = WebSocketHandler.get_handler(socket) |
|
86
|
1 |
|
cls.add_handler(handler) |
|
87
|
1 |
|
return handler |
|
88
|
|
|
|
|
89
|
1 |
|
@classmethod |
|
90
|
1 |
|
def add_handler(cls, handler): |
|
91
|
|
|
"""Add handler to loggers. |
|
92
|
|
|
|
|
93
|
|
|
Use formatter_console if it exists. |
|
94
|
|
|
|
|
95
|
|
|
Args: |
|
96
|
|
|
handler (:mod:`logging.handlers`): Handle to be added. |
|
97
|
|
|
""" |
|
98
|
1 |
|
if cls._PARSER.has_section(cls._DEFAULT_FMT): |
|
99
|
1 |
|
fmt_conf = cls._PARSER[cls._DEFAULT_FMT] |
|
100
|
1 |
|
fmt = Formatter(fmt_conf.get('format', None), |
|
101
|
|
|
fmt_conf.get('datefmt', None)) |
|
102
|
1 |
|
handler.setFormatter(fmt) |
|
103
|
1 |
|
handler.addFilter(cls.filter_session_disconnected) |
|
104
|
1 |
|
getLogger().addHandler(handler) |
|
105
|
|
|
|
|
106
|
1 |
|
@staticmethod |
|
107
|
1 |
|
def filter_session_disconnected(record): |
|
108
|
|
|
"""Remove harmless session disconnected error. |
|
109
|
|
|
|
|
110
|
|
|
Despite this error, everything seems to be working. As we can't catch |
|
111
|
|
|
it anywhere, we filter it. |
|
112
|
|
|
""" |
|
113
|
1 |
|
msg_end = "KeyError: 'Session is disconnected'" |
|
114
|
1 |
|
return not (record.name == 'werkzeug' and record.levelname == 'ERROR' |
|
115
|
|
|
and record.args and isinstance(record.args[0], str) |
|
116
|
|
|
and record.args[0].endswith(msg_end)) |
|
117
|
|
|
|
|
118
|
|
|
|
|
119
|
|
|
# Add filter to all pre-existing handlers |
|
120
|
1 |
|
HANDLER_FILTER = LogManager.filter_session_disconnected |
|
121
|
1 |
|
for root_handler in logging.root.handlers: |
|
122
|
1 |
|
if HANDLER_FILTER not in root_handler.filters: |
|
123
|
1 |
|
root_handler.addFilter(HANDLER_FILTER) |
|
124
|
|
|
|
|
125
|
|
|
|
|
126
|
1 |
|
class NAppLog: |
|
127
|
|
|
"""High-level logger for NApp devs. |
|
128
|
|
|
|
|
129
|
|
|
From NApp dev's point of view: |
|
130
|
|
|
- No need for instantiation |
|
131
|
|
|
- Logger name is automatically assigned |
|
132
|
|
|
|
|
133
|
|
|
Redirect all calls to a logger with the correct name (NApp ID). |
|
134
|
|
|
|
|
135
|
|
|
The appropriate logger is a logging.Logger with NApp ID as its name. If no |
|
136
|
|
|
NApp is found, use the root logger. |
|
137
|
|
|
|
|
138
|
|
|
As any NApp can use this logger, its name is detected in every call by |
|
139
|
|
|
inspecting the caller's stack. If no NApp is found, use the root logger. |
|
140
|
|
|
""" |
|
141
|
|
|
|
|
142
|
1 |
|
def __getattribute__(self, name): |
|
143
|
|
|
"""Detect NApp ID and use its logger.""" |
|
144
|
1 |
|
return get_napp_logger().__getattribute__(name) |
|
145
|
|
|
|
|
146
|
|
|
|
|
147
|
1 |
|
def get_napp_logger(): |
|
148
|
|
|
"""Detect NApp ID and get its logger.""" |
|
149
|
1 |
|
napp_id = _detect_napp_id() |
|
150
|
1 |
|
logger = getLogger("kytos.napps") |
|
151
|
|
|
|
|
152
|
|
|
# if napp_id is detected, get the napp logger. |
|
153
|
1 |
|
if napp_id: |
|
154
|
1 |
|
logger = logger.getChild(napp_id) |
|
155
|
|
|
|
|
156
|
1 |
|
return logger |
|
157
|
|
|
|
|
158
|
|
|
|
|
159
|
|
|
#: Detect NApp ID from filename |
|
160
|
1 |
|
NAPP_ID_RE = re.compile(r'.*napps/(.*?)/(.*?)/') |
|
161
|
|
|
|
|
162
|
|
|
|
|
163
|
1 |
|
def _detect_napp_id(): |
|
164
|
|
|
"""Get the last called NApp in caller's stack. |
|
165
|
|
|
|
|
166
|
|
|
We use the last innermost NApp because a NApp *A* may call a NApp *B* and, |
|
167
|
|
|
when *B* uses the logger, the logger's name should be *B*. |
|
168
|
|
|
|
|
169
|
|
|
Returns: |
|
170
|
|
|
str, None: NApp ID or None if no NApp is found in the caller's stack. |
|
171
|
|
|
|
|
172
|
|
|
""" |
|
173
|
1 |
|
for frame in inspect.stack(): |
|
174
|
1 |
|
if not frame.filename == __file__: |
|
175
|
1 |
|
match = NAPP_ID_RE.match(frame.filename) |
|
176
|
1 |
|
if match: |
|
177
|
1 |
|
return '/'.join(match.groups()) |
|
178
|
|
|
return None |
|
179
|
|
|
|