X-Git-Url: http://git.onelab.eu/?a=blobdiff_plain;f=python%2Fovs%2Fvlog.py;h=580b1bc23961f8abd57b62516c23adabe7cb03f0;hb=a5ed8fe32cb3c996837c61af2e358fa34dc9936f;hp=b585591b61212274d6eb73486432823ef65f1285;hpb=e0edde6fee279cdbbf3c179f5f50adaf0c7c7f1e;p=sliver-openvswitch.git diff --git a/python/ovs/vlog.py b/python/ovs/vlog.py index b585591b6..580b1bc23 100644 --- a/python/ovs/vlog.py +++ b/python/ovs/vlog.py @@ -1,5 +1,5 @@ -# Copyright (c) 2011 Nicira, Inc. +# Copyright (c) 2011, 2012, 2013 Nicira, Inc. # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. @@ -16,13 +16,22 @@ import datetime import logging import logging.handlers +import os +import re import socket import sys +import threading import ovs.dirs +import ovs.unixctl import ovs.util FACILITIES = {"console": "info", "file": "info", "syslog": "info"} +PATTERNS = { + "console": "%D{%Y-%m-%dT%H:%M:%SZ}|%05N|%c%T|%p|%m", + "file": "%D{%Y-%m-%dT%H:%M:%S.###Z}|%05N|%c%T|%p|%m", + "syslog": "ovs|%05N|%c%T|%p|%m", +} LEVELS = { "dbg": logging.DEBUG, "info": logging.INFO, @@ -40,7 +49,11 @@ def get_level(level_str): class Vlog: __inited = False __msg_num = 0 + __start_time = 0 __mfl = {} # Module -> facility -> level + __log_file = None + __file_handler = None + __log_patterns = PATTERNS def __init__(self, name): """Creates a new Vlog object representing a module called 'name'. The @@ -56,17 +69,96 @@ class Vlog: if not Vlog.__inited: return - now = datetime.datetime.now().strftime("%b %d %H:%M:%S") - message = ("%s|%s|%s|%s|%s" - % (now, Vlog.__msg_num, self.name, level, message)) - - level = LEVELS.get(level.lower(), logging.DEBUG) + level_num = LEVELS.get(level.lower(), logging.DEBUG) + msg_num = Vlog.__msg_num Vlog.__msg_num += 1 for f, f_level in Vlog.__mfl[self.name].iteritems(): f_level = LEVELS.get(f_level, logging.CRITICAL) - if level >= f_level: - logging.getLogger(f).log(level, message, **kwargs) + if level_num >= f_level: + msg = self._build_message(message, f, level, msg_num) + logging.getLogger(f).log(level_num, msg, **kwargs) + + def _build_message(self, message, facility, level, msg_num): + pattern = self.__log_patterns[facility] + tmp = pattern + + tmp = self._format_time(tmp) + + matches = re.findall("(%-?[0]?[0-9]?[AcmNnpPrtT])", tmp) + for m in matches: + if "A" in m: + tmp = self._format_field(tmp, m, ovs.util.PROGRAM_NAME) + elif "c" in m: + tmp = self._format_field(tmp, m, self.name) + elif "m" in m: + tmp = self._format_field(tmp, m, message) + elif "N" in m: + tmp = self._format_field(tmp, m, str(msg_num)) + elif "n" in m: + tmp = re.sub(m, "\n", tmp) + elif "p" in m: + tmp = self._format_field(tmp, m, level.upper()) + elif "P" in m: + self._format_field(tmp, m, str(os.getpid())) + elif "r" in m: + now = datetime.datetime.utcnow() + delta = now - self.__start_time + ms = delta.microseconds / 1000 + tmp = self._format_field(tmp, m, str(ms)) + elif "t" in m: + subprogram = threading.current_thread().name + if subprogram == "MainThread": + subprogram = "main" + tmp = self._format_field(tmp, m, subprogram) + elif "T" in m: + subprogram = threading.current_thread().name + if not subprogram == "MainThread": + subprogram = "({})".format(subprogram) + else: + subprogram = "" + tmp = self._format_field(tmp, m, subprogram) + return tmp.strip() + + def _format_field(self, tmp, match, replace): + formatting = re.compile("^%(0)?([1-9])?") + matches = formatting.match(match) + # Do we need to apply padding? + if not matches.group(1) and replace != "": + replace = replace.center(len(replace)+2) + # Does the field have a minimum width + if matches.group(2): + min_width = int(matches.group(2)) + if len(replace) < min_width: + replace = replace.center(min_width) + return re.sub(match, replace, tmp) + + def _format_time(self, tmp): + date_regex = re.compile('(%(0?[1-9]?[dD])(\{(.*)\})?)') + match = date_regex.search(tmp) + + if match is None: + return tmp + + # UTC date or Local TZ? + if match.group(2) == "d": + now = datetime.datetime.now() + elif match.group(2) == "D": + now = datetime.datetime.utcnow() + + # Custom format or ISO format? + if match.group(3): + time = datetime.date.strftime(now, match.group(4)) + try: + i = len(re.search("#+", match.group(4)).group(0)) + msec = '{0:0>{i}.{i}}'.format(str(now.microsecond / 1000), i=i) + time = re.sub('#+', msec, time) + except AttributeError: + pass + else: + time = datetime.datetime.isoformat(now.replace(microsecond=0)) + + return self._format_field(tmp, match.group(1), time) def emer(self, message, **kwargs): self.__log("EMER", message, **kwargs) @@ -83,6 +175,29 @@ class Vlog: def dbg(self, message, **kwargs): self.__log("DBG", message, **kwargs) + def __is_enabled(self, level): + level = LEVELS.get(level.lower(), logging.DEBUG) + for f, f_level in Vlog.__mfl[self.name].iteritems(): + f_level = LEVELS.get(f_level, logging.CRITICAL) + if level >= f_level: + return True + return False + + def emer_is_enabled(self): + return self.__is_enabled("EMER") + + def err_is_enabled(self): + return self.__is_enabled("ERR") + + def warn_is_enabled(self): + return self.__is_enabled("WARN") + + def info_is_enabled(self): + return self.__is_enabled("INFO") + + def dbg_is_enabled(self): + return self.__is_enabled("DBG") + def exception(self, message): """Logs 'message' at ERR log level. Includes a backtrace when in exception context.""" @@ -98,7 +213,9 @@ class Vlog: return Vlog.__inited = True + Vlog.__start_time = datetime.datetime.utcnow() logging.raiseExceptions = False + Vlog.__log_file = log_file for f in FACILITIES: logger = logging.getLogger(f) logger.setLevel(logging.DEBUG) @@ -110,11 +227,19 @@ class Vlog: logger.addHandler(logging.handlers.SysLogHandler( address="/dev/log", facility=logging.handlers.SysLogHandler.LOG_DAEMON)) - elif f == "file" and log_file: - logger.addHandler(logging.FileHandler(log_file)) + elif f == "file" and Vlog.__log_file: + Vlog.__file_handler = logging.FileHandler(Vlog.__log_file) + logger.addHandler(Vlog.__file_handler) except (IOError, socket.error): logger.setLevel(logging.CRITICAL) + ovs.unixctl.command_register("vlog/reopen", "", 0, 0, + Vlog._unixctl_vlog_reopen, None) + ovs.unixctl.command_register("vlog/set", "spec", 1, sys.maxint, + Vlog._unixctl_vlog_set, None) + ovs.unixctl.command_register("vlog/list", "", 0, 0, + Vlog._unixctl_vlog_list, None) + @staticmethod def set_level(module, facility, level): """ Sets the log level of the 'module'-'facility' tuple to 'level'. @@ -149,6 +274,95 @@ class Vlog: for f in facilities: Vlog.__mfl[m][f] = level + @staticmethod + def set_pattern(facility, pattern): + """ Sets the log pattern of the 'facility' to 'pattern' """ + facility = facility.lower() + Vlog.__log_patterns[facility] = pattern + + @staticmethod + def set_levels_from_string(s): + module = None + level = None + facility = None + + words = re.split('[ :]', s) + if words[0] == "pattern": + try: + if words[1] in FACILITIES and words[2]: + segments = [words[i] for i in range(2, len(words))] + pattern = "".join(segments) + Vlog.set_pattern(words[1], pattern) + return + else: + return "Facility %s does not exist" % words[1] + except IndexError: + return "Please supply a valid pattern and facility" + + for word in [w.lower() for w in words]: + if word == "any": + pass + elif word in FACILITIES: + if facility: + return "cannot specify multiple facilities" + facility = word + elif word in LEVELS: + if level: + return "cannot specify multiple levels" + level = word + elif word in Vlog.__mfl: + if module: + return "cannot specify multiple modules" + module = word + else: + return "no facility, level, or module \"%s\"" % word + + Vlog.set_level(module or "any", facility or "any", level or "any") + + @staticmethod + def get_levels(): + lines = [" console syslog file\n", + " ------- ------ ------\n"] + lines.extend(sorted(["%-16s %4s %4s %4s\n" + % (m, + Vlog.__mfl[m]["console"], + Vlog.__mfl[m]["syslog"], + Vlog.__mfl[m]["file"]) for m in Vlog.__mfl])) + return ''.join(lines) + + @staticmethod + def reopen_log_file(): + """Closes and then attempts to re-open the current log file. (This is + useful just after log rotation, to ensure that the new log file starts + being used.)""" + + if Vlog.__log_file: + logger = logging.getLogger("file") + logger.removeHandler(Vlog.__file_handler) + Vlog.__file_handler = logging.FileHandler(Vlog.__log_file) + logger.addHandler(Vlog.__file_handler) + + @staticmethod + def _unixctl_vlog_reopen(conn, unused_argv, unused_aux): + if Vlog.__log_file: + Vlog.reopen_log_file() + conn.reply(None) + else: + conn.reply("Logging to file not configured") + + @staticmethod + def _unixctl_vlog_set(conn, argv, unused_aux): + for arg in argv: + msg = Vlog.set_levels_from_string(arg) + if msg: + conn.reply(msg) + return + conn.reply(None) + + @staticmethod + def _unixctl_vlog_list(conn, unused_argv, unused_aux): + conn.reply(Vlog.get_levels()) + def add_args(parser): """Adds vlog related options to 'parser', an ArgumentParser object. The @@ -160,7 +374,7 @@ def add_args(parser): " is used if LOG_FILE is omitted.") group.add_argument("-v", "--verbose", nargs="*", help="Sets logging levels, see ovs-vswitchd(8)." - " Defaults to ANY:ANY:dbg.") + " Defaults to dbg.") def handle_args(args): @@ -178,23 +392,8 @@ def handle_args(args): args.verbose = ["any:any:dbg"] for verbose in args.verbose: - args = verbose.split(':') - - if len(args) >= 3: - level = args[2] - else: - level = "dbg" - - if len(args) >= 2: - facility = args[1] - else: - facility = "any" - - if len(args) >= 1: - module = args[0] - else: - module = "any" - - Vlog.set_level(module, facility, level) + msg = Vlog.set_levels_from_string(verbose) + if msg: + ovs.util.ovs_fatal(0, "processing \"%s\": %s" % (verbose, msg)) Vlog.init(log_file)