]>
Commit | Line | Data |
---|---|---|
8ed182d8 | 1 | |
ad8d7af7 | 2 | # Copyright (c) 2011, 2012, 2013 Nicira, Inc. |
8ed182d8 EJ |
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 | import datetime | |
17 | import logging | |
18 | import logging.handlers | |
a5ed8fe3 | 19 | import os |
f26ddb5b | 20 | import re |
8ed182d8 EJ |
21 | import socket |
22 | import sys | |
a5ed8fe3 | 23 | import threading |
8ed182d8 EJ |
24 | |
25 | import ovs.dirs | |
8ba37945 | 26 | import ovs.unixctl |
8ed182d8 EJ |
27 | import ovs.util |
28 | ||
d5460484 | 29 | DESTINATIONS = {"console": "info", "file": "info", "syslog": "info"} |
a5ed8fe3 DT |
30 | PATTERNS = { |
31 | "console": "%D{%Y-%m-%dT%H:%M:%SZ}|%05N|%c%T|%p|%m", | |
32 | "file": "%D{%Y-%m-%dT%H:%M:%S.###Z}|%05N|%c%T|%p|%m", | |
33 | "syslog": "ovs|%05N|%c%T|%p|%m", | |
34 | } | |
8ed182d8 EJ |
35 | LEVELS = { |
36 | "dbg": logging.DEBUG, | |
37 | "info": logging.INFO, | |
38 | "warn": logging.WARNING, | |
39 | "err": logging.ERROR, | |
40 | "emer": logging.CRITICAL, | |
41 | "off": logging.CRITICAL | |
42 | } | |
d69d61c7 GS |
43 | FACILITIES = ['auth', 'authpriv', 'cron', 'daemon', 'ftp', 'kern', 'lpr', |
44 | 'mail', 'news', 'syslog', 'user', 'uucp', 'local0', 'local1', | |
45 | 'local2', 'local3', 'local4', 'local5', 'local6', 'local7'] | |
46 | syslog_facility = "daemon" | |
47 | syslog_handler = '' | |
8ed182d8 EJ |
48 | |
49 | ||
50 | def get_level(level_str): | |
51 | return LEVELS.get(level_str.lower()) | |
52 | ||
53 | ||
54 | class Vlog: | |
55 | __inited = False | |
56 | __msg_num = 0 | |
a5ed8fe3 | 57 | __start_time = 0 |
d5460484 | 58 | __mfl = {} # Module -> destination -> level |
8ba37945 BP |
59 | __log_file = None |
60 | __file_handler = None | |
a5ed8fe3 | 61 | __log_patterns = PATTERNS |
8ed182d8 EJ |
62 | |
63 | def __init__(self, name): | |
64 | """Creates a new Vlog object representing a module called 'name'. The | |
65 | created Vlog object will do nothing until the Vlog.init() static method | |
66 | is called. Once called, no more Vlog objects may be created.""" | |
67 | ||
68 | assert not Vlog.__inited | |
69 | self.name = name.lower() | |
70 | if name not in Vlog.__mfl: | |
d5460484 | 71 | Vlog.__mfl[self.name] = DESTINATIONS.copy() |
8ed182d8 EJ |
72 | |
73 | def __log(self, level, message, **kwargs): | |
74 | if not Vlog.__inited: | |
75 | return | |
76 | ||
a5ed8fe3 DT |
77 | level_num = LEVELS.get(level.lower(), logging.DEBUG) |
78 | msg_num = Vlog.__msg_num | |
8ed182d8 EJ |
79 | Vlog.__msg_num += 1 |
80 | ||
81 | for f, f_level in Vlog.__mfl[self.name].iteritems(): | |
82 | f_level = LEVELS.get(f_level, logging.CRITICAL) | |
a5ed8fe3 DT |
83 | if level_num >= f_level: |
84 | msg = self._build_message(message, f, level, msg_num) | |
85 | logging.getLogger(f).log(level_num, msg, **kwargs) | |
86 | ||
d5460484 GS |
87 | def _build_message(self, message, destination, level, msg_num): |
88 | pattern = self.__log_patterns[destination] | |
a5ed8fe3 DT |
89 | tmp = pattern |
90 | ||
91 | tmp = self._format_time(tmp) | |
92 | ||
93 | matches = re.findall("(%-?[0]?[0-9]?[AcmNnpPrtT])", tmp) | |
94 | for m in matches: | |
95 | if "A" in m: | |
96 | tmp = self._format_field(tmp, m, ovs.util.PROGRAM_NAME) | |
97 | elif "c" in m: | |
98 | tmp = self._format_field(tmp, m, self.name) | |
99 | elif "m" in m: | |
100 | tmp = self._format_field(tmp, m, message) | |
101 | elif "N" in m: | |
102 | tmp = self._format_field(tmp, m, str(msg_num)) | |
103 | elif "n" in m: | |
104 | tmp = re.sub(m, "\n", tmp) | |
105 | elif "p" in m: | |
106 | tmp = self._format_field(tmp, m, level.upper()) | |
107 | elif "P" in m: | |
108 | self._format_field(tmp, m, str(os.getpid())) | |
109 | elif "r" in m: | |
110 | now = datetime.datetime.utcnow() | |
111 | delta = now - self.__start_time | |
112 | ms = delta.microseconds / 1000 | |
113 | tmp = self._format_field(tmp, m, str(ms)) | |
114 | elif "t" in m: | |
dde7b5cd | 115 | subprogram = threading.currentThread().getName() |
a5ed8fe3 DT |
116 | if subprogram == "MainThread": |
117 | subprogram = "main" | |
118 | tmp = self._format_field(tmp, m, subprogram) | |
119 | elif "T" in m: | |
dde7b5cd | 120 | subprogram = threading.currentThread().getName() |
a5ed8fe3 DT |
121 | if not subprogram == "MainThread": |
122 | subprogram = "({})".format(subprogram) | |
420f4b46 | 123 | else: |
a5ed8fe3 DT |
124 | subprogram = "" |
125 | tmp = self._format_field(tmp, m, subprogram) | |
126 | return tmp.strip() | |
127 | ||
128 | def _format_field(self, tmp, match, replace): | |
129 | formatting = re.compile("^%(0)?([1-9])?") | |
130 | matches = formatting.match(match) | |
131 | # Do we need to apply padding? | |
132 | if not matches.group(1) and replace != "": | |
133 | replace = replace.center(len(replace)+2) | |
134 | # Does the field have a minimum width | |
135 | if matches.group(2): | |
136 | min_width = int(matches.group(2)) | |
137 | if len(replace) < min_width: | |
138 | replace = replace.center(min_width) | |
139 | return re.sub(match, replace, tmp) | |
140 | ||
141 | def _format_time(self, tmp): | |
142 | date_regex = re.compile('(%(0?[1-9]?[dD])(\{(.*)\})?)') | |
143 | match = date_regex.search(tmp) | |
144 | ||
145 | if match is None: | |
146 | return tmp | |
147 | ||
148 | # UTC date or Local TZ? | |
149 | if match.group(2) == "d": | |
150 | now = datetime.datetime.now() | |
151 | elif match.group(2) == "D": | |
152 | now = datetime.datetime.utcnow() | |
153 | ||
154 | # Custom format or ISO format? | |
155 | if match.group(3): | |
156 | time = datetime.date.strftime(now, match.group(4)) | |
157 | try: | |
158 | i = len(re.search("#+", match.group(4)).group(0)) | |
159 | msec = '{0:0>{i}.{i}}'.format(str(now.microsecond / 1000), i=i) | |
160 | time = re.sub('#+', msec, time) | |
161 | except AttributeError: | |
162 | pass | |
163 | else: | |
164 | time = datetime.datetime.isoformat(now.replace(microsecond=0)) | |
165 | ||
166 | return self._format_field(tmp, match.group(1), time) | |
8ed182d8 EJ |
167 | |
168 | def emer(self, message, **kwargs): | |
169 | self.__log("EMER", message, **kwargs) | |
170 | ||
171 | def err(self, message, **kwargs): | |
172 | self.__log("ERR", message, **kwargs) | |
173 | ||
174 | def warn(self, message, **kwargs): | |
175 | self.__log("WARN", message, **kwargs) | |
176 | ||
177 | def info(self, message, **kwargs): | |
178 | self.__log("INFO", message, **kwargs) | |
179 | ||
180 | def dbg(self, message, **kwargs): | |
181 | self.__log("DBG", message, **kwargs) | |
182 | ||
03922c90 BP |
183 | def __is_enabled(self, level): |
184 | level = LEVELS.get(level.lower(), logging.DEBUG) | |
185 | for f, f_level in Vlog.__mfl[self.name].iteritems(): | |
186 | f_level = LEVELS.get(f_level, logging.CRITICAL) | |
187 | if level >= f_level: | |
188 | return True | |
189 | return False | |
190 | ||
191 | def emer_is_enabled(self): | |
192 | return self.__is_enabled("EMER") | |
193 | ||
194 | def err_is_enabled(self): | |
195 | return self.__is_enabled("ERR") | |
196 | ||
197 | def warn_is_enabled(self): | |
198 | return self.__is_enabled("WARN") | |
199 | ||
200 | def info_is_enabled(self): | |
201 | return self.__is_enabled("INFO") | |
202 | ||
203 | def dbg_is_enabled(self): | |
204 | return self.__is_enabled("DBG") | |
205 | ||
8ed182d8 EJ |
206 | def exception(self, message): |
207 | """Logs 'message' at ERR log level. Includes a backtrace when in | |
208 | exception context.""" | |
209 | self.err(message, exc_info=True) | |
210 | ||
211 | @staticmethod | |
212 | def init(log_file=None): | |
213 | """Intializes the Vlog module. Causes Vlog to write to 'log_file' if | |
214 | not None. Should be called after all Vlog objects have been created. | |
215 | No logging will occur until this function is called.""" | |
216 | ||
217 | if Vlog.__inited: | |
218 | return | |
219 | ||
220 | Vlog.__inited = True | |
a5ed8fe3 | 221 | Vlog.__start_time = datetime.datetime.utcnow() |
8ed182d8 | 222 | logging.raiseExceptions = False |
8ba37945 | 223 | Vlog.__log_file = log_file |
d5460484 | 224 | for f in DESTINATIONS: |
8ed182d8 EJ |
225 | logger = logging.getLogger(f) |
226 | logger.setLevel(logging.DEBUG) | |
227 | ||
228 | try: | |
229 | if f == "console": | |
230 | logger.addHandler(logging.StreamHandler(sys.stderr)) | |
231 | elif f == "syslog": | |
d69d61c7 | 232 | Vlog.add_syslog_handler() |
8ba37945 BP |
233 | elif f == "file" and Vlog.__log_file: |
234 | Vlog.__file_handler = logging.FileHandler(Vlog.__log_file) | |
235 | logger.addHandler(Vlog.__file_handler) | |
8ed182d8 EJ |
236 | except (IOError, socket.error): |
237 | logger.setLevel(logging.CRITICAL) | |
238 | ||
8ba37945 BP |
239 | ovs.unixctl.command_register("vlog/reopen", "", 0, 0, |
240 | Vlog._unixctl_vlog_reopen, None) | |
f26ddb5b BP |
241 | ovs.unixctl.command_register("vlog/set", "spec", 1, sys.maxint, |
242 | Vlog._unixctl_vlog_set, None) | |
243 | ovs.unixctl.command_register("vlog/list", "", 0, 0, | |
244 | Vlog._unixctl_vlog_list, None) | |
8ba37945 | 245 | |
8ed182d8 | 246 | @staticmethod |
d5460484 GS |
247 | def set_level(module, destination, level): |
248 | """ Sets the log level of the 'module'-'destination' tuple to 'level'. | |
8ed182d8 EJ |
249 | All three arguments are strings which are interpreted the same as |
250 | arguments to the --verbose flag. Should be called after all Vlog | |
251 | objects have already been created.""" | |
252 | ||
253 | module = module.lower() | |
d5460484 | 254 | destination = destination.lower() |
8ed182d8 EJ |
255 | level = level.lower() |
256 | ||
d5460484 | 257 | if destination != "any" and destination not in DESTINATIONS: |
8ed182d8 EJ |
258 | return |
259 | ||
260 | if module != "any" and module not in Vlog.__mfl: | |
261 | return | |
262 | ||
263 | if level not in LEVELS: | |
264 | return | |
265 | ||
266 | if module == "any": | |
267 | modules = Vlog.__mfl.keys() | |
268 | else: | |
269 | modules = [module] | |
270 | ||
d5460484 GS |
271 | if destination == "any": |
272 | destinations = DESTINATIONS.keys() | |
8ed182d8 | 273 | else: |
d5460484 | 274 | destinations = [destination] |
8ed182d8 EJ |
275 | |
276 | for m in modules: | |
d5460484 | 277 | for f in destinations: |
8ed182d8 EJ |
278 | Vlog.__mfl[m][f] = level |
279 | ||
a5ed8fe3 | 280 | @staticmethod |
d5460484 GS |
281 | def set_pattern(destination, pattern): |
282 | """ Sets the log pattern of the 'destination' to 'pattern' """ | |
283 | destination = destination.lower() | |
284 | Vlog.__log_patterns[destination] = pattern | |
a5ed8fe3 | 285 | |
d69d61c7 GS |
286 | @staticmethod |
287 | def add_syslog_handler(facility=None): | |
288 | global syslog_facility, syslog_handler | |
289 | ||
290 | # If handler is already added and there is no change in 'facility', | |
291 | # there is nothing to do. | |
292 | if (not facility or facility == syslog_facility) and syslog_handler: | |
293 | return | |
294 | ||
d69d61c7 | 295 | logger = logging.getLogger('syslog') |
7905aae3 GS |
296 | # If there is no infrastructure to support python syslog, increase |
297 | # the logging severity level to avoid repeated errors. | |
298 | if not os.path.isfile("/dev/log"): | |
299 | logger.setLevel(logging.CRITICAL) | |
300 | return | |
301 | ||
d69d61c7 GS |
302 | if syslog_handler: |
303 | logger.removeHandler(syslog_handler) | |
7905aae3 GS |
304 | |
305 | if facility: | |
306 | syslog_facility = facility | |
307 | ||
d69d61c7 GS |
308 | syslog_handler = logging.handlers.SysLogHandler(address="/dev/log", |
309 | facility=syslog_facility) | |
310 | logger.addHandler(syslog_handler) | |
311 | return | |
312 | ||
f26ddb5b BP |
313 | @staticmethod |
314 | def set_levels_from_string(s): | |
315 | module = None | |
316 | level = None | |
d5460484 | 317 | destination = None |
f26ddb5b | 318 | |
a5ed8fe3 DT |
319 | words = re.split('[ :]', s) |
320 | if words[0] == "pattern": | |
321 | try: | |
d5460484 | 322 | if words[1] in DESTINATIONS and words[2]: |
a5ed8fe3 DT |
323 | segments = [words[i] for i in range(2, len(words))] |
324 | pattern = "".join(segments) | |
325 | Vlog.set_pattern(words[1], pattern) | |
326 | return | |
327 | else: | |
d5460484 | 328 | return "Destination %s does not exist" % words[1] |
a5ed8fe3 | 329 | except IndexError: |
d5460484 | 330 | return "Please supply a valid pattern and destination" |
d69d61c7 GS |
331 | elif words[0] == "FACILITY": |
332 | if words[1] in FACILITIES: | |
333 | Vlog.add_syslog_handler(words[1]) | |
334 | return | |
335 | else: | |
336 | return "Facility %s is invalid" % words[1] | |
a5ed8fe3 DT |
337 | |
338 | for word in [w.lower() for w in words]: | |
f26ddb5b BP |
339 | if word == "any": |
340 | pass | |
d5460484 GS |
341 | elif word in DESTINATIONS: |
342 | if destination: | |
343 | return "cannot specify multiple destinations" | |
344 | destination = word | |
f26ddb5b BP |
345 | elif word in LEVELS: |
346 | if level: | |
347 | return "cannot specify multiple levels" | |
348 | level = word | |
349 | elif word in Vlog.__mfl: | |
350 | if module: | |
351 | return "cannot specify multiple modules" | |
352 | module = word | |
353 | else: | |
d5460484 | 354 | return "no destination, level, or module \"%s\"" % word |
f26ddb5b | 355 | |
d5460484 | 356 | Vlog.set_level(module or "any", destination or "any", level or "any") |
f26ddb5b BP |
357 | |
358 | @staticmethod | |
359 | def get_levels(): | |
360 | lines = [" console syslog file\n", | |
361 | " ------- ------ ------\n"] | |
362 | lines.extend(sorted(["%-16s %4s %4s %4s\n" | |
363 | % (m, | |
364 | Vlog.__mfl[m]["console"], | |
365 | Vlog.__mfl[m]["syslog"], | |
366 | Vlog.__mfl[m]["file"]) for m in Vlog.__mfl])) | |
367 | return ''.join(lines) | |
368 | ||
8ba37945 BP |
369 | @staticmethod |
370 | def reopen_log_file(): | |
371 | """Closes and then attempts to re-open the current log file. (This is | |
372 | useful just after log rotation, to ensure that the new log file starts | |
373 | being used.)""" | |
374 | ||
375 | if Vlog.__log_file: | |
376 | logger = logging.getLogger("file") | |
377 | logger.removeHandler(Vlog.__file_handler) | |
378 | Vlog.__file_handler = logging.FileHandler(Vlog.__log_file) | |
379 | logger.addHandler(Vlog.__file_handler) | |
380 | ||
381 | @staticmethod | |
382 | def _unixctl_vlog_reopen(conn, unused_argv, unused_aux): | |
383 | if Vlog.__log_file: | |
384 | Vlog.reopen_log_file() | |
385 | conn.reply(None) | |
386 | else: | |
387 | conn.reply("Logging to file not configured") | |
8ed182d8 | 388 | |
f26ddb5b BP |
389 | @staticmethod |
390 | def _unixctl_vlog_set(conn, argv, unused_aux): | |
391 | for arg in argv: | |
392 | msg = Vlog.set_levels_from_string(arg) | |
393 | if msg: | |
394 | conn.reply(msg) | |
395 | return | |
396 | conn.reply(None) | |
397 | ||
398 | @staticmethod | |
399 | def _unixctl_vlog_list(conn, unused_argv, unused_aux): | |
400 | conn.reply(Vlog.get_levels()) | |
401 | ||
a5ed8fe3 | 402 | |
8ed182d8 EJ |
403 | def add_args(parser): |
404 | """Adds vlog related options to 'parser', an ArgumentParser object. The | |
405 | resulting arguments parsed by 'parser' should be passed to handle_args.""" | |
406 | ||
407 | group = parser.add_argument_group(title="Logging Options") | |
408 | group.add_argument("--log-file", nargs="?", const="default", | |
409 | help="Enables logging to a file. Default log file" | |
410 | " is used if LOG_FILE is omitted.") | |
411 | group.add_argument("-v", "--verbose", nargs="*", | |
412 | help="Sets logging levels, see ovs-vswitchd(8)." | |
f26ddb5b | 413 | " Defaults to dbg.") |
8ed182d8 EJ |
414 | |
415 | ||
416 | def handle_args(args): | |
417 | """ Handles command line arguments ('args') parsed by an ArgumentParser. | |
418 | The ArgumentParser should have been primed by add_args(). Also takes care | |
419 | of initializing the Vlog module.""" | |
420 | ||
421 | log_file = args.log_file | |
422 | if log_file == "default": | |
423 | log_file = "%s/%s.log" % (ovs.dirs.LOGDIR, ovs.util.PROGRAM_NAME) | |
424 | ||
425 | if args.verbose is None: | |
426 | args.verbose = [] | |
427 | elif args.verbose == []: | |
428 | args.verbose = ["any:any:dbg"] | |
429 | ||
430 | for verbose in args.verbose: | |
f26ddb5b BP |
431 | msg = Vlog.set_levels_from_string(verbose) |
432 | if msg: | |
433 | ovs.util.ovs_fatal(0, "processing \"%s\": %s" % (verbose, msg)) | |
8ed182d8 EJ |
434 | |
435 | Vlog.init(log_file) |