|
1
|
|
|
# encoding: utf-8 |
|
2
|
|
|
""" |
|
3
|
|
|
logger.py |
|
4
|
|
|
|
|
5
|
|
|
Created by Thomas Mangin on 2009-09-06. |
|
6
|
|
|
Copyright (c) 2009-2017 Exa Networks. All rights reserved. |
|
7
|
|
|
License: 3-clause BSD. (See the COPYRIGHT file) |
|
8
|
|
|
""" |
|
9
|
|
|
|
|
10
|
|
|
from __future__ import print_function |
|
11
|
|
|
|
|
12
|
|
|
import os |
|
13
|
|
|
import sys |
|
14
|
|
|
import stat |
|
15
|
|
|
import time |
|
16
|
|
|
import syslog |
|
17
|
|
|
import logging |
|
18
|
|
|
import logging.handlers |
|
19
|
|
|
import pdb |
|
20
|
|
|
from collections import deque |
|
21
|
|
|
|
|
22
|
|
|
from exabgp.util.od import od |
|
23
|
|
|
from exabgp.environment import getenv |
|
24
|
|
|
from exabgp.environment import APPLICATION |
|
25
|
|
|
|
|
26
|
|
|
|
|
27
|
|
|
def _can_write(location): |
|
28
|
|
|
try: |
|
29
|
|
|
s = os.stat(os.path.dirname(location)) |
|
30
|
|
|
except OSError: |
|
31
|
|
|
return None |
|
32
|
|
|
mode = s[stat.ST_MODE] |
|
33
|
|
|
uid = os.geteuid() |
|
34
|
|
|
gid = os.getegid() |
|
35
|
|
|
|
|
36
|
|
|
return not not ( |
|
37
|
|
|
((s[stat.ST_UID] == uid) and (mode & stat.S_IWUSR)) |
|
38
|
|
|
or ((s[stat.ST_GID] == gid) and (mode & stat.S_IWGRP)) |
|
39
|
|
|
or (mode & stat.S_IWOTH) |
|
40
|
|
|
) |
|
41
|
|
|
|
|
42
|
|
|
|
|
43
|
|
|
# This delays the evaluation of the od() function which is expensive |
|
44
|
|
|
# hence why pylint too-few-public-method is disabled |
|
45
|
|
|
|
|
46
|
|
|
|
|
47
|
|
|
class LazyFormat(object): |
|
48
|
|
|
def __init__(self, prefix, message, formater=od): |
|
49
|
|
|
self.prefix = prefix |
|
50
|
|
|
self.message = message |
|
51
|
|
|
self.formater = formater |
|
52
|
|
|
|
|
53
|
|
|
def split(self, char): |
|
54
|
|
|
return str(self).split(char) |
|
55
|
|
|
|
|
56
|
|
|
def __str__(self): |
|
57
|
|
|
formated = self.formater(self.message) |
|
58
|
|
|
return '%s (%4d) %s' % (self.prefix, len(self.message), formated) |
|
59
|
|
|
|
|
60
|
|
|
|
|
61
|
|
|
class LazyAttribute(object): |
|
62
|
|
|
def __init__(self, flag, aid, length, data): |
|
63
|
|
|
self.flag = flag |
|
64
|
|
|
self.aid = aid |
|
65
|
|
|
self.length = length |
|
66
|
|
|
self.data = data |
|
67
|
|
|
|
|
68
|
|
|
def split(self, char): |
|
69
|
|
|
return str(self).split(char) |
|
70
|
|
|
|
|
71
|
|
|
def __str__(self): |
|
72
|
|
|
return 'attribute %-18s flag 0x%02x type 0x%02x len 0x%02x%s' % ( |
|
73
|
|
|
str(self.aid), |
|
74
|
|
|
self.flag, |
|
75
|
|
|
int(self.aid), |
|
76
|
|
|
self.length, |
|
77
|
|
|
' payload %s' % od(self.data) if self.data else '', |
|
78
|
|
|
) |
|
79
|
|
|
|
|
80
|
|
|
|
|
81
|
|
|
class LazyNLRI(object): |
|
82
|
|
|
def __init__(self, afi, safi, addpath, data): |
|
83
|
|
|
self.afi = afi |
|
84
|
|
|
self.safi = safi |
|
85
|
|
|
self.addpath = addpath |
|
86
|
|
|
self.data = data |
|
87
|
|
|
|
|
88
|
|
|
def split(self, char): |
|
89
|
|
|
return str(self).split(char) |
|
90
|
|
|
|
|
91
|
|
|
def __str__(self): |
|
92
|
|
|
family = '%s %s' % (self.afi, self.safi) |
|
93
|
|
|
path = 'with path-information' if self.addpath else 'without path-information' |
|
94
|
|
|
payload = od(self.data) if self.data else 'none' |
|
95
|
|
|
return 'NLRI %-18s %-28s payload %s' % (family, path, payload) |
|
96
|
|
|
|
|
97
|
|
|
|
|
98
|
|
|
def istty(std): |
|
99
|
|
|
try: |
|
100
|
|
|
return std.isatty() |
|
101
|
|
|
except KeyboardInterrupt: |
|
102
|
|
|
raise |
|
103
|
|
|
except Exception: |
|
104
|
|
|
return False |
|
105
|
|
|
|
|
106
|
|
|
|
|
107
|
|
|
class Logger(object): |
|
108
|
|
|
RECORD = { |
|
109
|
|
|
'START': '\033[01;32m', # Green |
|
110
|
|
|
'DEBUG': '', |
|
111
|
|
|
'INFO': '\033[01;32m', # Green |
|
112
|
|
|
'NOTICE': '\033[01;34m', # Blue |
|
113
|
|
|
'WARNING': '\033[01;33m', # Yellow |
|
114
|
|
|
'ERR': '\033[01;31m', # Red |
|
115
|
|
|
'CRIT': '\033[00;31m', # Strong Red |
|
116
|
|
|
} |
|
117
|
|
|
|
|
118
|
|
|
MESSAGE = { |
|
119
|
|
|
'START': '\033[1m', # Green |
|
120
|
|
|
'DEBUG': '', |
|
121
|
|
|
'INFO': '\033[1m', # Green |
|
122
|
|
|
'NOTICE': '\033[1m', # Blue |
|
123
|
|
|
'WARNING': '\033[1m', # Yellow |
|
124
|
|
|
'ERR': '\033[1m', # Red |
|
125
|
|
|
'CRIT': '\033[1m', # Strong Red |
|
126
|
|
|
} |
|
127
|
|
|
|
|
128
|
|
|
END = '\033[0m' |
|
129
|
|
|
|
|
130
|
|
|
TTY = { |
|
131
|
|
|
'stderr': lambda: istty(sys.stderr), |
|
132
|
|
|
'stdout': lambda: istty(sys.stdout), |
|
133
|
|
|
'out': lambda: istty(sys.stdout), |
|
134
|
|
|
} |
|
135
|
|
|
|
|
136
|
|
|
_instance = dict() |
|
137
|
|
|
_syslog = None |
|
138
|
|
|
_where = '' |
|
139
|
|
|
|
|
140
|
|
|
_history = deque() |
|
141
|
|
|
_max_history = 20 |
|
142
|
|
|
|
|
143
|
|
|
_default = None |
|
144
|
|
|
|
|
145
|
|
|
_config = '' |
|
146
|
|
|
_pid = os.getpid() |
|
147
|
|
|
_cwd = os.getcwd() |
|
148
|
|
|
|
|
149
|
|
|
_instance = None |
|
150
|
|
|
|
|
151
|
|
|
def __new__(cls): |
|
152
|
|
|
if cls._instance is None: |
|
153
|
|
|
cls._instance = super(Logger, cls).__new__(cls) |
|
154
|
|
|
return cls._instance |
|
155
|
|
|
|
|
156
|
|
|
# we use os.pid everytime as we may fork and the class is instance before it |
|
157
|
|
|
|
|
158
|
|
|
def pdb(self, level): |
|
159
|
|
|
if self._option['pdb'] and level == 'CRIT': |
|
160
|
|
|
# not sure why, pylint reports an import error here |
|
161
|
|
|
pdb.set_trace() |
|
162
|
|
|
|
|
163
|
|
|
def config(self, config=None): |
|
164
|
|
|
if config is not None: |
|
165
|
|
|
self._config = config |
|
166
|
|
|
return self._config |
|
167
|
|
|
|
|
168
|
|
|
def history(self): |
|
169
|
|
|
return "\n".join(self._format(*_) for _ in self._history) |
|
170
|
|
|
|
|
171
|
|
|
def _record(self, timestamp, message, source, level): |
|
172
|
|
|
if len(self._history) > self._max_history: |
|
173
|
|
|
self._history.popleft() |
|
174
|
|
|
self._history.append((message, source, level, timestamp)) |
|
175
|
|
|
|
|
176
|
|
|
def init(self): |
|
177
|
|
|
env = getenv() |
|
178
|
|
|
|
|
179
|
|
|
self.short = env.log.short |
|
180
|
|
|
self.level = env.log.level |
|
181
|
|
|
|
|
182
|
|
|
self._option = { |
|
183
|
|
|
'pdb': env.debug.pdb, |
|
184
|
|
|
'reactor': env.log.enable and (env.log.all or env.log.reactor), |
|
185
|
|
|
'daemon': env.log.enable and (env.log.all or env.log.daemon), |
|
186
|
|
|
'processes': env.log.enable and (env.log.all or env.log.processes), |
|
187
|
|
|
'configuration': env.log.enable and (env.log.all or env.log.configuration), |
|
188
|
|
|
'network': env.log.enable and (env.log.all or env.log.network), |
|
189
|
|
|
'wire': env.log.enable and (env.log.all or env.log.packets), |
|
190
|
|
|
'message': env.log.enable and (env.log.all or env.log.message), |
|
191
|
|
|
'rib': env.log.enable and (env.log.all or env.log.rib), |
|
192
|
|
|
'timer': env.log.enable and (env.log.all or env.log.timers), |
|
193
|
|
|
'routes': env.log.enable and (env.log.all or env.log.routes), |
|
194
|
|
|
'parser': env.log.enable and (env.log.all or env.log.parser), |
|
195
|
|
|
} |
|
196
|
|
|
|
|
197
|
|
|
if not env.log.enable: |
|
198
|
|
|
self.destination = '' |
|
199
|
|
|
return |
|
200
|
|
|
|
|
201
|
|
|
self.destination = env.log.destination |
|
202
|
|
|
|
|
203
|
|
|
self.restart(True) |
|
204
|
|
|
|
|
205
|
|
|
def _local_syslog(self): |
|
206
|
|
|
if sys.platform == "darwin": |
|
207
|
|
|
address = '/var/run/syslog' |
|
208
|
|
|
else: |
|
209
|
|
|
address = '/dev/log' |
|
210
|
|
|
if not os.path.exists(address): |
|
211
|
|
|
address = ('localhost', 514) |
|
212
|
|
|
handler = logging.handlers.SysLogHandler(address) |
|
213
|
|
|
|
|
214
|
|
|
self._syslog.addHandler(handler) |
|
215
|
|
|
return True |
|
216
|
|
|
|
|
217
|
|
|
def _remote_syslog(self, destination): |
|
218
|
|
|
# If the address is invalid, each syslog call will print an error. |
|
219
|
|
|
# See how it can be avoided, as the socket error is encapsulated and not returned |
|
220
|
|
|
address = (destination, 514) |
|
221
|
|
|
handler = logging.handlers.SysLogHandler(address) |
|
222
|
|
|
|
|
223
|
|
|
self._syslog.addHandler(handler) |
|
224
|
|
|
return True |
|
225
|
|
|
|
|
226
|
|
|
def _standard(self, facility): |
|
227
|
|
|
handler = logging.StreamHandler(getattr(sys, facility)) |
|
228
|
|
|
|
|
229
|
|
|
self._syslog.addHandler(handler) |
|
230
|
|
|
return True |
|
231
|
|
|
|
|
232
|
|
|
def _file(self, destination): |
|
233
|
|
|
# folder |
|
234
|
|
|
logfile = os.path.realpath(os.path.normpath(os.path.join(self._cwd, destination))) |
|
235
|
|
|
can = _can_write(logfile) |
|
236
|
|
|
if can is True: |
|
237
|
|
|
handler = logging.handlers.RotatingFileHandler(logfile, maxBytes=5 * 1024 * 1024, backupCount=5) |
|
238
|
|
|
elif can is None: |
|
239
|
|
|
self.critical('ExaBGP can not access (perhaps as it does not exist) the log folder provided', 'logger') |
|
240
|
|
|
return False |
|
241
|
|
|
else: |
|
242
|
|
|
self.critical('ExaBGP does not have the right to write in the requested log directory', 'logger') |
|
243
|
|
|
return False |
|
244
|
|
|
|
|
245
|
|
|
self._syslog.addHandler(handler) |
|
246
|
|
|
return True |
|
247
|
|
|
|
|
248
|
|
|
def restart(self, first=False): |
|
249
|
|
|
try: |
|
250
|
|
|
if first: |
|
251
|
|
|
self._where = 'stdout' |
|
252
|
|
|
self._default = logging.StreamHandler(sys.stdout) |
|
253
|
|
|
self._syslog = logging.getLogger() |
|
254
|
|
|
self._syslog.setLevel(logging.DEBUG) |
|
255
|
|
|
self._syslog.addHandler(self._default) |
|
256
|
|
|
return True |
|
257
|
|
|
except IOError: |
|
258
|
|
|
# no way to report anything via stdout, silently failing |
|
259
|
|
|
return False |
|
260
|
|
|
|
|
261
|
|
|
if not self._syslog: |
|
262
|
|
|
# no way to report anything via stdout, silently failing |
|
263
|
|
|
return False |
|
264
|
|
|
|
|
265
|
|
|
for handler in self._syslog.handlers: |
|
266
|
|
|
self._syslog.removeHandler(handler) |
|
267
|
|
|
self._syslog.addHandler(self._default) |
|
268
|
|
|
|
|
269
|
|
|
try: |
|
270
|
|
|
if self.destination == 'stderr': |
|
271
|
|
|
self._where = 'stderr' |
|
272
|
|
|
return True |
|
273
|
|
|
elif self.destination == 'stdout': |
|
274
|
|
|
self._where = 'out' |
|
275
|
|
|
result = self._standard(self.destination) |
|
276
|
|
|
elif self.destination in ('', 'syslog'): |
|
277
|
|
|
self._where = 'syslog' |
|
278
|
|
|
result = self._local_syslog() |
|
279
|
|
|
elif self.destination.startswith('host:'): |
|
280
|
|
|
self._where = 'syslog' |
|
281
|
|
|
result = self._remote_syslog(self.destination[5:].strip()) |
|
282
|
|
|
else: |
|
283
|
|
|
self._where = 'file' |
|
284
|
|
|
result = self._file(self.destination) |
|
285
|
|
|
|
|
286
|
|
|
if result: |
|
287
|
|
|
self._syslog.removeHandler(self._default) |
|
288
|
|
|
return result |
|
289
|
|
|
except IOError: |
|
290
|
|
|
self.critical('Can not set logging (are stdout/stderr closed?)', 'logger') |
|
291
|
|
|
return False |
|
292
|
|
|
|
|
293
|
|
|
def _format(self, message, source, level, timestamp=None): |
|
294
|
|
|
if timestamp is None: |
|
295
|
|
|
timestamp = time.localtime() |
|
296
|
|
|
self._record(timestamp, message, source, level) |
|
297
|
|
|
|
|
298
|
|
|
if self.short: |
|
299
|
|
|
return message |
|
300
|
|
|
|
|
301
|
|
|
if self._where in ['stdout', 'stderr', 'out']: |
|
302
|
|
|
now = time.strftime('%H:%M:%S', timestamp) |
|
303
|
|
|
if not self.TTY[self._where](): |
|
304
|
|
|
return "%s | %-6d | %-15s | %s" % (now, self._pid, source, message) |
|
305
|
|
|
return "%s | %-6d | %s%-13s%s | %s%-8s%s" % ( |
|
306
|
|
|
now, |
|
307
|
|
|
self._pid, |
|
308
|
|
|
self.RECORD.get(level, ''), |
|
309
|
|
|
source, |
|
310
|
|
|
self.END, |
|
311
|
|
|
self.MESSAGE.get(level, ''), |
|
312
|
|
|
message, |
|
313
|
|
|
self.END, |
|
314
|
|
|
) |
|
315
|
|
|
elif self._where in [ |
|
316
|
|
|
'syslog', |
|
317
|
|
|
]: |
|
318
|
|
|
return "%s[%d]: %-13s %s" % (APPLICATION, self._pid, source, message) |
|
319
|
|
|
elif self._where in [ |
|
320
|
|
|
'file', |
|
321
|
|
|
]: |
|
322
|
|
|
now = time.strftime('%a, %d %b %Y %H:%M:%S', timestamp) |
|
323
|
|
|
return "%s %-6d %-13s %s" % (now, self._pid, source, message) |
|
324
|
|
|
else: |
|
325
|
|
|
# failsafe |
|
326
|
|
|
return "%s | %-8s | %-6d | %-13s | %s" % (now, level, self._pid, source, message) |
|
|
|
|
|
|
327
|
|
|
|
|
328
|
|
|
def _report(self, message, source, level): |
|
329
|
|
|
if source.startswith('incoming-'): |
|
330
|
|
|
src = 'wire' |
|
331
|
|
|
elif source.startswith('outgoing-'): |
|
332
|
|
|
src = 'wire' |
|
333
|
|
|
elif source.startswith('ka-'): |
|
334
|
|
|
src = 'timer' |
|
335
|
|
|
elif source.startswith('peer-'): |
|
336
|
|
|
src = 'network' |
|
337
|
|
|
else: |
|
338
|
|
|
src = source |
|
339
|
|
|
|
|
340
|
|
|
log = self._option.get(src, True) and getattr(syslog, 'LOG_%s' % level) <= self.level |
|
341
|
|
|
|
|
342
|
|
|
if not log: |
|
343
|
|
|
return |
|
344
|
|
|
|
|
345
|
|
|
for line in message.split('\n'): |
|
346
|
|
|
if self._syslog: |
|
347
|
|
|
self._syslog.debug(self._format(line, source, level)) |
|
348
|
|
|
else: |
|
349
|
|
|
print(self._format(line, source, level)) |
|
350
|
|
|
sys.stdout.flush() |
|
351
|
|
|
|
|
352
|
|
|
def debug(self, message, source='', level='DEBUG'): |
|
353
|
|
|
self._report(message, source, level) |
|
354
|
|
|
|
|
355
|
|
|
def info(self, message, source='', level='INFO'): |
|
356
|
|
|
self._report(message, source, level) |
|
357
|
|
|
|
|
358
|
|
|
def notice(self, message, source='', level='NOTICE'): |
|
359
|
|
|
self._report(message, source, level) |
|
360
|
|
|
|
|
361
|
|
|
def warning(self, message, source='', level='WARNING'): |
|
362
|
|
|
self._report(message, source, level) |
|
363
|
|
|
|
|
364
|
|
|
def error(self, message, source='', level='ERR'): |
|
365
|
|
|
self._report(message, source, level) |
|
366
|
|
|
|
|
367
|
|
|
def critical(self, message, source='', level='CRIT'): |
|
368
|
|
|
self._report(message, source, level) |
|
369
|
|
|
|
|
370
|
|
|
|
|
371
|
|
|
log = Logger() |
|
372
|
|
|
|