diff --git a/supervisor/dispatchers.py b/supervisor/dispatchers.py index f0e17104c..01fba9713 100644 --- a/supervisor/dispatchers.py +++ b/supervisor/dispatchers.py @@ -126,15 +126,19 @@ def _init_normallog(self): maxbytes = getattr(config, '%s_logfile_maxbytes' % channel) backups = getattr(config, '%s_logfile_backups' % channel) to_syslog = getattr(config, '%s_syslog' % channel) + loglevel = getattr(config, 'loglevel') + logformat = getattr(config, 'logformat') + logformatter = getattr(config, 'logformatter') if logfile or to_syslog: - self.normallog = config.options.getLogger() + self.normallog = config.options.getLogger(loglevel) if logfile: loggers.handle_file( self.normallog, filename=logfile, - fmt='%(message)s', + fmt=logformat, + formatter=logformatter, rotating=not not maxbytes, # optimization maxbytes=maxbytes, backups=backups diff --git a/supervisor/jsonformatter.py b/supervisor/jsonformatter.py new file mode 100644 index 000000000..6af281b17 --- /dev/null +++ b/supervisor/jsonformatter.py @@ -0,0 +1,227 @@ +# Including python-json-logger module here as advised in logger.py +# https://github.com/madzak/python-json-logger/blob/master/src/pythonjsonlogger/jsonlogger.py +''' +This library is provided to allow standard python logging +to output log data as JSON formatted strings +''' +import logging +import json +import re +from datetime import date, datetime, time +import traceback +import importlib + +from inspect import istraceback + +from collections import OrderedDict + +# skip natural LogRecord attributes +# http://docs.python.org/library/logging.html#logrecord-attributes +RESERVED_ATTRS = ( + 'args', 'asctime', 'created', 'exc_info', 'exc_text', 'filename', + 'funcName', 'levelname', 'levelno', 'lineno', 'module', + 'msecs', 'message', 'msg', 'name', 'pathname', 'process', + 'processName', 'relativeCreated', 'stack_info', 'thread', 'threadName') + +try: + from datetime import timezone + time_converter = lambda timestamp: datetime.fromtimestamp(timestamp, tz=timezone.utc) +except ImportError: + # Python 2 + time_converter = lambda timestamp: datetime.utcfromtimestamp(timestamp) + +def merge_record_extra(record, target, reserved): + """ + Merges extra attributes from LogRecord object into target dictionary + + :param record: logging.LogRecord + :param target: dict to update + :param reserved: dict or list with reserved keys to skip + """ + for key, value in record.__dict__.items(): + # this allows to have numeric keys + if (key not in reserved + and not (hasattr(key, "startswith") + and key.startswith('_'))): + target[key] = value + return target + + +class JsonEncoder(json.JSONEncoder): + """ + A custom encoder extending the default JSONEncoder + """ + + def default(self, obj): + if isinstance(obj, (date, datetime, time)): + return self.format_datetime_obj(obj) + + elif istraceback(obj): + return ''.join(traceback.format_tb(obj)).strip() + + elif type(obj) == Exception \ + or isinstance(obj, Exception) \ + or type(obj) == type: + return str(obj) + + try: + return super(JsonEncoder, self).default(obj) + + except TypeError: + try: + return str(obj) + + except Exception: + return None + + def format_datetime_obj(self, obj): + return obj.isoformat() + + +class JsonFormatter(logging.Formatter): + """ + A custom formatter to format logging records as json strings. + Extra values will be formatted as str() if not supported by + json default encoder + """ + + def __init__(self, *args, **kwargs): + """ + :param json_default: a function for encoding non-standard objects + as outlined in http://docs.python.org/2/library/json.html + :param json_encoder: optional custom encoder + :param json_serializer: a :meth:`json.dumps`-compatible callable + that will be used to serialize the log record. + :param json_indent: an optional :meth:`json.dumps`-compatible numeric value + that will be used to customize the indent of the output json. + :param prefix: an optional string prefix added at the beginning of + the formatted string + :param rename_fields: an optional dict, used to rename field names in the output. + Rename message to @message: {'message': '@message'} + :param json_indent: indent parameter for json.dumps + :param json_ensure_ascii: ensure_ascii parameter for json.dumps + :param reserved_attrs: an optional list of fields that will be skipped when + outputting json log record. Defaults to all log record attributes: + http://docs.python.org/library/logging.html#logrecord-attributes + :param timestamp: an optional string/boolean field to add a timestamp when + outputting the json log record. If string is passed, timestamp will be added + to log record using string as key. If True boolean is passed, timestamp key + will be "timestamp". Defaults to False/off. + """ + self.json_default = self._str_to_fn(kwargs.pop("json_default", None)) + self.json_encoder = self._str_to_fn(kwargs.pop("json_encoder", None)) + self.json_serializer = self._str_to_fn(kwargs.pop("json_serializer", json.dumps)) + self.json_indent = kwargs.pop("json_indent", None) + self.json_ensure_ascii = kwargs.pop("json_ensure_ascii", True) + self.prefix = kwargs.pop("prefix", "") + self.rename_fields = kwargs.pop("rename_fields", {}) + reserved_attrs = kwargs.pop("reserved_attrs", RESERVED_ATTRS) + self.reserved_attrs = dict(zip(reserved_attrs, reserved_attrs)) + self.timestamp = kwargs.pop("timestamp", False) + + # super(JsonFormatter, self).__init__(*args, **kwargs) + logging.Formatter.__init__(self, *args, **kwargs) + if not self.json_encoder and not self.json_default: + self.json_encoder = JsonEncoder + + self._required_fields = self.parse() + self._skip_fields = dict(zip(self._required_fields, + self._required_fields)) + self._skip_fields.update(self.reserved_attrs) + + def _str_to_fn(self, fn_as_str): + """ + If the argument is not a string, return whatever was passed in. + Parses a string such as package.module.function, imports the module + and returns the function. + + :param fn_as_str: The string to parse. If not a string, return it. + """ + if not isinstance(fn_as_str, str): + return fn_as_str + + path, _, function = fn_as_str.rpartition('.') + module = importlib.import_module(path) + return getattr(module, function) + + def parse(self): + """ + Parses format string looking for substitutions + + This method is responsible for returning a list of fields (as strings) + to include in all log messages. + """ + standard_formatters = re.compile(r'\((.+?)\)', re.IGNORECASE) + return standard_formatters.findall(self._fmt) + + def add_fields(self, log_record, record, message_dict): + """ + Override this method to implement custom logic for adding fields. + """ + for field in self._required_fields: + if field in self.rename_fields: + log_record[self.rename_fields[field]] = record.__dict__.get(field) + else: + log_record[field] = record.__dict__.get(field) + log_record.update(message_dict) + merge_record_extra(record, log_record, reserved=self._skip_fields) + + if self.timestamp: + key = self.timestamp if type(self.timestamp) == str else 'timestamp' + log_record[key] = time_converter(record.created) + + def process_log_record(self, log_record): + """ + Override this method to implement custom logic + on the possibly ordered dictionary. + """ + return log_record + + def jsonify_log_record(self, log_record): + """Returns a json string of the log record.""" + return self.json_serializer(log_record, + default=self.json_default, + cls=self.json_encoder, + indent=self.json_indent, + ensure_ascii=self.json_ensure_ascii) + + def serialize_log_record(self, log_record): + """Returns the final representation of the log record.""" + return "%s%s" % (self.prefix, self.jsonify_log_record(log_record)) + + def format(self, record): + """Formats a log record and serializes to json""" + message_dict = {} + if isinstance(record.msg, dict): + message_dict = record.msg + record.message = None + else: + record.message = record.getMessage() + # only format time if needed + if "asctime" in self._required_fields: + record.asctime = self.formatTime(record, self.datefmt) + + # Display formatted exception, but allow overriding it in the + # user-supplied dict. + if record.exc_info and not message_dict.get('exc_info'): + message_dict['exc_info'] = self.formatException(record.exc_info) + if not message_dict.get('exc_info') and record.exc_text: + message_dict['exc_info'] = record.exc_text + # Display formatted record of stack frames + # default format is a string returned from :func:`traceback.print_stack` + try: + if record.stack_info and not message_dict.get('stack_info'): + message_dict['stack_info'] = self.formatStack(record.stack_info) + except AttributeError: + # Python2.7 doesn't have stack_info. + pass + + try: + log_record = OrderedDict() + except NameError: + log_record = {} + + self.add_fields(log_record, record, message_dict) + log_record = self.process_log_record(log_record) + + return self.serialize_log_record(log_record) diff --git a/supervisor/loggers.py b/supervisor/loggers.py index 44d14b44c..2eb04f9b1 100644 --- a/supervisor/loggers.py +++ b/supervisor/loggers.py @@ -12,11 +12,20 @@ import sys import time import traceback +import logging +import json +import re from supervisor.compat import syslog from supervisor.compat import long from supervisor.compat import is_text_stream from supervisor.compat import as_string +from supervisor.compat import as_bytes +from supervisor.jsonformatter import JsonFormatter +from string import Template +from string import Formatter as StrFormatter +from collections import OrderedDict + class LevelsByName: CRIT = 50 # messages that probably require immediate user attention @@ -44,21 +53,233 @@ def _levelNumbers(): return bynumber LOG_LEVELS_BY_NUM = _levelNumbers() +_str_formatter = StrFormatter() +del StrFormatter def getLevelNumByDescription(description): num = getattr(LevelsByDescription, description, None) return num +class PercentStyle(logging.PercentStyle): + validation_pattern = re.compile(r'%\(\w+\)[#0+ -]*(\*|\d+)?(\.(\*|\d+))?[diouxefgcrsa%]', re.I) + + def validate(self): + """Validate the input format, ensure it matches the correct style""" + if not self.validation_pattern.search(self._fmt): + raise ValueError("Invalid format '%s' for '%s' style" % (self._fmt, self.default_format[0])) + +class StrFormatStyle(logging.StrFormatStyle): + fmt_spec = re.compile(r'^(.?[<>=^])?[+ -]?#?0?(\d+|{\w+})?[,_]?(\.(\d+|{\w+}))?[bcdefgnosx%]?$', re.I) + field_spec = re.compile(r'^(\d+|\w+)(\.\w+|\[[^]]+\])*$') + + def _format(self, record): + return self._fmt.format(**record.__dict__) + + def validate(self): + """Validate the input format, ensure it is the correct string formatting style""" + fields = set() + try: + for _, fieldname, spec, conversion in _str_formatter.parse(self._fmt): + if fieldname: + if not self.field_spec.match(fieldname): + raise ValueError('invalid field name/expression: %r' % fieldname) + fields.add(fieldname) + if conversion and conversion not in 'rsa': + raise ValueError('invalid conversion: %r' % conversion) + if spec and not self.fmt_spec.match(spec): + raise ValueError('bad specifier: %r' % spec) + except ValueError as e: + raise ValueError('invalid format: %s' % e) + if not fields: + raise ValueError('invalid format: no fields') + + +class StringTemplateStyle(logging.StringTemplateStyle): + def validate(self): + pattern = Template.pattern + fields = set() + for m in pattern.finditer(self._fmt): + d = m.groupdict() + if d['named']: + fields.add(d['named']) + elif d['braced']: + fields.add(d['braced']) + elif m.group(0) == '$': + raise ValueError('invalid format: bare \'$\' not allowed') + if not fields: + raise ValueError('invalid format: no fields') + +BASIC_FORMAT = "%(message)s" +_STYLES = { + '%': (PercentStyle, BASIC_FORMAT), + '$': (StringTemplateStyle, '${message}'), + '{': (StrFormatStyle, '{message}') +} + +class PlainTextFormatter(logging.Formatter): + def __init__(self, *args, **kwargs): + """Constructor.""" + self.fields_with_default_value = kwargs.pop('fields_with_default_value', {}) + self.fmt_terminator = '' + + fmt = args[0] + if fmt.endswith('\n'): + self.fmt_terminator = '\n' + fmt = fmt.rstrip('\n') + elif fmt.endswith('\\n'): + self.fmt_terminator = '\n' + fmt = fmt.rstrip('\\n') + args = (fmt,) + args[1:] + + super().__init__(*args, **kwargs) + + + def format(self, record): + # Add the fields with the default values first and then + # overwrite the default values with the existing LogReocrd fields. + _record = self.fields_with_default_value.copy() + _record.update(record.__dict__) + record.__dict__ = _record + + record.message = record.getMessage() + + if self.usesTime(): + record.asctime = self.formatTime(record, self.datefmt) + + return self.formatMessage(record) + self.fmt_terminator + +class CustomJsonFormatter(JsonFormatter): + def __init__(self, *args, **kwargs): + """Constructor.""" + self.fields_with_default_value = kwargs.pop('fields_with_default_value', {}) + super().__init__(*args, **kwargs) + reserved_attrs = ('level', 'levelname', 'msg', 'kw', 'dictrepr', 'created', 'msecs') + self._skip_fields.update((v, v) for v in reserved_attrs) + self.fmt_terminator = '\n' + + def parse(self): + """ + Parses format string looking for substitutions + This method is responsible for returning a list of fields (as strings) + to include in all log messages. + """ + if isinstance(self._style, logging.StringTemplateStyle): + formatter_style_pattern = re.compile(r'\$\{(.+?)\}', re.IGNORECASE) + elif isinstance(self._style, logging.StrFormatStyle): + formatter_style_pattern = re.compile(r'\{(.+?)\}', re.IGNORECASE) + # PercentStyle is parent class of StringTemplateStyle and StrFormatStyle so + # it needs to be checked last. + elif isinstance(self._style, logging.PercentStyle): + formatter_style_pattern = re.compile(r'%\((.+?)\)s', re.IGNORECASE) + else: + raise ValueError('Invalid format: %s' % self._fmt) + return formatter_style_pattern.findall(self._fmt) + + def serialize_log_record(self, log_record): + """Returns the final representation of the log record.""" + return "%s%s" % (self.prefix, self.jsonify_log_record(log_record)) + + def format(self, record): + """Formats a log record and serializes to json""" + # Add the fields with the default values first and then + # overwrite the default values with the existing LogReocrd fields. + _record = self.fields_with_default_value.copy() + _record.update(record.__dict__) + record.__dict__ = _record + + message_dict = {} + if isinstance(record.msg, dict): + message_dict = record.msg + record.message = None + else: + message = record.getMessage() + try: + json_message = json.loads(message) + # The json parser accepts numbers as a valid json. + # But we want json objects only. + if isinstance(json_message, dict): + message_dict = json_message + record.message = None + else: + del json_message + record.message = as_string(message).rstrip('\n') + except json.decoder.JSONDecodeError: + record.message = as_string(message).rstrip('\n') + + # only format time if needed + if "asctime" in self._required_fields: + record.asctime = self.formatTime(record, self.datefmt) + + try: + log_record = OrderedDict() + except NameError: + log_record = {} + + self.add_fields(log_record, record, message_dict) + log_record = self.process_log_record(log_record) + return self.serialize_log_record(log_record) + self.fmt_terminator + + +class FormatterFactory: + def get_formatter(self, name=None, fmt=None, style=None): + if name is None: + name = 'plaintext' + + if fmt is None: + fmt = '%(asctime)s %(levelname)s %(message)s' + + fmt, fields_with_default_value = self.get_fields_default_values(fmt) + + if style is None: + style = self.get_logformat_style(fmt) + + if name == 'plaintext': + return PlainTextFormatter(fmt, style=style, fields_with_default_value=fields_with_default_value) + if name == 'json': + return CustomJsonFormatter(fmt, style=style, fields_with_default_value=fields_with_default_value) + raise ValueError('Invalid formatter name: %s' % name) + + def get_logformat_style(self, fmt): + """Determine the string format style based on the logformat.""" + for style in _STYLES: + _style = _STYLES[style][0](fmt) + try: + _style.validate() + return style # return style if fmt passes style validation + except ValueError: + style = None + else: + raise ValueError('Invalid logging format: %s (%s)' % (fmt, type(fmt))) + + def get_fields_default_values(self, fmt): + fields_with_default_value = {} + placeholder_pattern = re.compile(r'[\{\(](.+?)[\}\)]', re.IGNORECASE) + for placeholder in placeholder_pattern.findall(fmt): + kv = placeholder.split(':', 1) + if len(kv) == 2: + key, val = kv + fields_with_default_value[key] = val + # remove the default value from the format string + fmt = fmt.replace(placeholder, key) + return fmt, fields_with_default_value + + +_formatter_factory = FormatterFactory().get_formatter +BASIC_FORMATTER = _formatter_factory(name='plaintext', fmt=BASIC_FORMAT) + class Handler: - fmt = '%(message)s' level = LevelsByName.INFO + terminator = '' def __init__(self, stream=None): self.stream = stream self.closed = False + self.formatter = BASIC_FORMATTER - def setFormat(self, fmt): - self.fmt = fmt + def setFormatter(self, formatter): + if type(formatter) not in [PlainTextFormatter, CustomJsonFormatter]: + raise ValueError('Invalid formatter: %s (%s)' % (formatter, type(formatter))) + self.formatter = formatter def setLevel(self, level): self.level = level @@ -88,16 +309,7 @@ def close(self): def emit(self, record): try: - binary = (self.fmt == '%(message)s' and - isinstance(record.msg, bytes) and - (not record.kw or record.kw == {'exc_info': None})) - binary_stream = not is_text_stream(self.stream) - if binary: - msg = record.msg - else: - msg = self.fmt % record.asdict() - if binary_stream: - msg = msg.encode('utf-8') + msg = self.formatter.format(record) try: self.stream.write(msg) except UnicodeError: @@ -105,7 +317,7 @@ def emit(self, record): # this only occurs because of a test stream type # which deliberately raises an exception the first # time it's called. So just do it again - self.stream.write(msg) + self.stream.write(msg + self.terminator) self.flush() except: self.handleError() @@ -116,6 +328,8 @@ def handleError(self): del ei class StreamHandler(Handler): + terminator = '' + def __init__(self, strm=None): Handler.__init__(self, strm) @@ -141,7 +355,7 @@ def write(self, b): blen = len(b) if len(self.buf) + blen > self.maxbytes: self.buf = self.buf[blen:] - self.buf += b + self.buf += as_bytes(b) def getvalue(self): return self.buf @@ -152,6 +366,7 @@ def clear(self): class FileHandler(Handler): """File handler which supports reopening of logs. """ + terminator = '' def __init__(self, filename, mode='ab'): Handler.__init__(self) @@ -185,6 +400,18 @@ def remove(self): if why.args[0] != errno.ENOENT: raise + def emit(self, record): + try: + msg = self.formatter.format(record) + if 'b' in self.mode: + msg = as_bytes(msg + self.terminator) + self.stream.write(msg) + else: + self.stream.write(msg + self.terminator) + self.flush() + except: + self.handleError() + class RotatingFileHandler(FileHandler): def __init__(self, filename, mode='ab', maxBytes=512*1024*1024, backupCount=10): @@ -278,15 +505,18 @@ def doRollover(self): class LogRecord: def __init__(self, level, msg, **kw): self.level = level + self.levelname = LOG_LEVELS_BY_NUM[level] self.msg = msg self.kw = kw self.dictrepr = None + self.created = time.time() + self.msecs = (self.created - int(self.created)) * 1000 def asdict(self): if self.dictrepr is None: - now = time.time() - msecs = (now - long(now)) * 1000 - part1 = time.strftime("%Y-%m-%d %H:%M:%S", time.localtime(now)) + ct = self.created + msecs = (ct - long(ct)) * 1000 + part1 = time.strftime("%Y-%m-%d %H:%M:%S", time.localtime(ct)) asctime = '%s,%03d' % (part1, msecs) levelname = LOG_LEVELS_BY_NUM[self.level] msg = as_string(self.msg) @@ -296,10 +526,25 @@ def asdict(self): 'asctime':asctime} return self.dictrepr + def getMessage(self): + if self.kw: + try: + return as_string(self.msg) % self.kw + except ValueError as e: + # Skip string interpolation when string + # formatting charcaters are not escaped. + return as_string(self.msg) + else: + return as_string(self.msg) + class Logger: def __init__(self, level=None, handlers=None): if level is None: level = LevelsByName.INFO + elif isinstance(level, str): + level = getLevelNumByDescription(level) + if not (LevelsByName.BLAT <= level <= LevelsByName.CRIT): + raise ValueError("Bad logger level value: '%s'" % level) self.level = level if handlers is None: @@ -352,6 +597,7 @@ def getvalue(self): class SyslogHandler(Handler): def __init__(self): + self.fmt = '%(message)s' Handler.__init__(self) assert syslog is not None, "Syslog module not present" @@ -371,7 +617,7 @@ def emit(self, record): message = params['message'] for line in message.rstrip('\n').split('\n'): params['message'] = line - msg = self.fmt % params + msg = self.fmt % params # TODO: Use parent Handler formatter. try: self._syslog(msg) except UnicodeError: @@ -384,30 +630,33 @@ def getLogger(level=None): _2MB = 1<<21 -def handle_boundIO(logger, fmt, maxbytes=_2MB): +def handle_boundIO(logger, fmt, formatter=None, maxbytes=_2MB): """Attach a new BoundIO handler to an existing Logger""" io = BoundIO(maxbytes) handler = StreamHandler(io) handler.setLevel(logger.level) - handler.setFormat(fmt) + _formatter = _formatter_factory(name=formatter, fmt=fmt) + handler.setFormatter(_formatter) logger.addHandler(handler) logger.getvalue = io.getvalue -def handle_stdout(logger, fmt): +def handle_stdout(logger, fmt, formatter=None): """Attach a new StreamHandler with stdout handler to an existing Logger""" handler = StreamHandler(sys.stdout) - handler.setFormat(fmt) + _formatter = _formatter_factory(name=formatter, fmt=fmt) + handler.setFormatter(_formatter) handler.setLevel(logger.level) logger.addHandler(handler) -def handle_syslog(logger, fmt): +def handle_syslog(logger, fmt, formatter=None): """Attach a new Syslog handler to an existing Logger""" handler = SyslogHandler() - handler.setFormat(fmt) + _formatter = _formatter_factory(name=formatter, fmt=fmt) + handler.setFormatter(_formatter) handler.setLevel(logger.level) logger.addHandler(handler) -def handle_file(logger, filename, fmt, rotating=False, maxbytes=0, backups=0): +def handle_file(logger, filename, fmt, formatter=None, rotating=False, maxbytes=0, backups=0): """Attach a new file handler to an existing Logger. If the filename is the magic name of 'syslog' then make it a syslog handler instead.""" if filename == 'syslog': # TODO remove this @@ -417,6 +666,8 @@ def handle_file(logger, filename, fmt, rotating=False, maxbytes=0, backups=0): handler = FileHandler(filename) else: handler = RotatingFileHandler(filename, 'a', maxbytes, backups) - handler.setFormat(fmt) + + _formatter = _formatter_factory(name=formatter, fmt=fmt) + handler.setFormatter(_formatter) handler.setLevel(logger.level) logger.addHandler(handler) diff --git a/supervisor/options.py b/supervisor/options.py index 7b53cc760..cc77cf8bf 100644 --- a/supervisor/options.py +++ b/supervisor/options.py @@ -433,6 +433,10 @@ def __init__(self): "z:", "logfile_backups=", integer, default=10) self.add("loglevel", "supervisord.loglevel", "e:", "loglevel=", logging_level, default="info") + self.add("logformat", "supervisord.logformat", + default="%(asctime)s %(levelname)s %(message)s\n") + self.add("logformatter", "supervisord.logformatter", + default="plaintext") self.add("pidfile", "supervisord.pidfile", "j:", "pidfile=", existing_dirpath, default="supervisord.pid") self.add("identifier", "supervisord.identifier", "i:", "identifier=", @@ -451,6 +455,7 @@ def __init__(self): "", "profile_options=", profile_options, default=None) self.add("silent", "supervisord.silent", "s", "silent", flag=1, default=0) + self.pidhistory = {} self.process_group_configs = [] self.parse_criticals = [] @@ -497,6 +502,14 @@ def realize(self, *arg, **kw): if not self.loglevel: self.loglevel = section.loglevel + if not self.logformat: + self.logformat = section.logformat + if not self.logformat.endswith('\n') and not self.logformat.endswith('\\n'): + self.logformat = self.logformat + '\n' + + if not self.logformatter: + self.logformatter = section.logformatter + if self.logfile: logfile = self.logfile else: @@ -643,6 +656,9 @@ def get(opt, default, **kwargs): section.logfile_maxbytes = byte_size(get('logfile_maxbytes', '50MB')) section.logfile_backups = integer(get('logfile_backups', 10)) section.loglevel = logging_level(get('loglevel', 'info')) + # Default to str.format style to avoid conflicting with environment variables expansion syntax. + section.logformat = get('logformat', '{asctime} {levelname} {message}\n') + section.logformatter = get('logformatter', 'plaintext') section.pidfile = existing_dirpath(get('pidfile', 'supervisord.pid')) section.identifier = get('identifier', 'supervisor') section.nodaemon = boolean(get('nodaemon', 'false')) @@ -930,6 +946,10 @@ def get(section, opt, *args, **kwargs): stderr_cmaxbytes = byte_size(get(section,'stderr_capture_maxbytes','0')) stderr_events = boolean(get(section, 'stderr_events_enabled','false')) serverurl = get(section, 'serverurl', None) + loglevel = logging_level(get(section, 'loglevel', 'info')) + # Default to str.format style to avoid conflicting with environment variables expansion syntax. + logformat = get(section, 'logformat', '{message}') + logformatter = get(section, 'logformatter', 'plaintext') if serverurl and serverurl.strip().upper() == 'AUTO': serverurl = None @@ -1057,7 +1077,11 @@ def get(section, opt, *args, **kwargs): exitcodes=exitcodes, redirect_stderr=redirect_stderr, environment=environment, - serverurl=serverurl) + serverurl=serverurl, + loglevel=loglevel, + logformat=logformat, + logformatter=logformatter + ) programs.append(pconfig) @@ -1487,14 +1511,14 @@ def set_rlimits_or_exit(self): def make_logger(self): # must be called after realize() and after supervisor does setuid() - format = '%(asctime)s %(levelname)s %(message)s\n' self.logger = loggers.getLogger(self.loglevel) if self.nodaemon and not self.silent: - loggers.handle_stdout(self.logger, format) + loggers.handle_stdout(self.logger, self.logformat, self.logformatter) loggers.handle_file( self.logger, self.logfile, - format, + self.logformat, + self.logformatter, rotating=not not self.logfile_maxbytes, maxbytes=self.logfile_maxbytes, backups=self.logfile_backups, @@ -1874,7 +1898,7 @@ class ProcessConfig(Config): 'stderr_logfile_backups', 'stderr_logfile_maxbytes', 'stderr_events_enabled', 'stderr_syslog', 'stopsignal', 'stopwaitsecs', 'stopasgroup', 'killasgroup', - 'exitcodes', 'redirect_stderr' ] + 'exitcodes', 'redirect_stderr', 'loglevel', 'logformat', 'logformatter'] optional_param_names = [ 'environment', 'serverurl' ] def __init__(self, options, **params): diff --git a/supervisor/tests/base.py b/supervisor/tests/base.py index bef82e964..530dcf0a3 100644 --- a/supervisor/tests/base.py +++ b/supervisor/tests/base.py @@ -41,6 +41,9 @@ def __init__(self): self.logger = self.getLogger() self.backofflimit = 10 self.logfile = '/tmp/logfile' + self.loglevel = 20 + self.logformat = '{message}' + self.logformatter = 'plaintext' self.nocleanup = False self.strip_ansi = False self.pidhistory = {} @@ -90,7 +93,7 @@ def __init__(self): self.changed_directory = False self.umaskset = None self.poller = DummyPoller(self) - self.silent = False + self.silent = False def getLogger(self, *args, **kw): logger = DummyLogger() @@ -520,7 +523,8 @@ def __init__(self, options, name, command, directory=None, umask=None, stderr_syslog=False, redirect_stderr=False, stopsignal=None, stopwaitsecs=10, stopasgroup=False, killasgroup=False, - exitcodes=(0,), environment=None, serverurl=None): + exitcodes=(0,), environment=None, serverurl=None, + loglevel='info', logformat='{message}', logformatter='plaintext'): self.options = options self.name = name self.command = command @@ -556,6 +560,9 @@ def __init__(self, options, name, command, directory=None, umask=None, self.umask = umask self.autochildlogs_created = False self.serverurl = serverurl + self.loglevel = loglevel + self.logformat = logformat + self.logformatter = logformatter def get_path(self): return ["/bin", "/usr/bin", "/usr/local/bin"] diff --git a/supervisor/tests/test_options.py b/supervisor/tests/test_options.py index 5c9a35f6d..de8297930 100644 --- a/supervisor/tests/test_options.py +++ b/supervisor/tests/test_options.py @@ -465,6 +465,8 @@ def test_options(self): logfile_maxbytes=1000MB logfile_backups=5 loglevel=error + logformat={message} + logformatter=plaintext pidfile=supervisord.pid nodaemon=true silent=true @@ -492,6 +494,9 @@ def test_options(self): startretries=10 directory=/tmp umask=002 + loglevel=error + logformat={message} + logformatter=plaintext [program:cat2] priority=2 @@ -540,6 +545,8 @@ def test_options(self): self.assertEqual(options.logfile_maxbytes, 1000 * 1024 * 1024) self.assertEqual(options.logfile_backups, 5) self.assertEqual(options.loglevel, 40) + self.assertEqual(options.logformat, '{message}') + self.assertEqual(options.logformatter, 'plaintext') self.assertEqual(options.pidfile, 'supervisord.pid') self.assertEqual(options.nodaemon, True) self.assertEqual(options.silent, True) @@ -583,6 +590,9 @@ def test_options(self): self.assertEqual(proc1.exitcodes, [0]) self.assertEqual(proc1.directory, '/tmp') self.assertEqual(proc1.umask, 2) + self.assertEqual(proc1.loglevel, 40) + self.assertEqual(proc1.logformat, '{message}') + self.assertEqual(proc1.logformatter, 'plaintext') self.assertEqual(proc1.environment, dict(FAKE_ENV_VAR='/some/path')) cat2 = options.process_group_configs[1] @@ -3337,6 +3347,9 @@ def _makeOne(self, *arg, **kw): for name in ('stdout_logfile_backups', 'stdout_logfile_maxbytes', 'stderr_logfile_backups', 'stderr_logfile_maxbytes'): defaults[name] = 10 + options = arg[0] + for name in ['loglevel', 'logformat', 'logformatter']: + defaults[name] = getattr(options, name) defaults.update(kw) return self._getTargetClass()(*arg, **defaults) @@ -3435,6 +3448,9 @@ def _makeOne(self, *arg, **kw): for name in ('stdout_logfile_backups', 'stdout_logfile_maxbytes', 'stderr_logfile_backups', 'stderr_logfile_maxbytes'): defaults[name] = 10 + options = arg[0] + for name in ['loglevel', 'logformat', 'logformatter']: + defaults[name] = getattr(options, name) defaults.update(kw) return self._getTargetClass()(*arg, **defaults) @@ -3478,11 +3494,14 @@ def _makeOne(self, *arg, **kw): 'stderr_events_enabled', 'stderr_syslog', 'stopsignal', 'stopwaitsecs', 'stopasgroup', 'killasgroup', 'exitcodes', 'redirect_stderr', - 'environment'): + 'environment', 'loglevel', 'logformat', 'logformatter'): defaults[name] = name for name in ('stdout_logfile_backups', 'stdout_logfile_maxbytes', 'stderr_logfile_backups', 'stderr_logfile_maxbytes'): defaults[name] = 10 + options = arg[0] + for name in ['loglevel', 'logformat', 'logformatter']: + defaults[name] = getattr(options, name) defaults.update(kw) return self._getTargetClass()(*arg, **defaults) diff --git a/supervisor/tests/test_supervisord.py b/supervisor/tests/test_supervisord.py index 3d7b4ffad..1afa028e0 100644 --- a/supervisor/tests/test_supervisord.py +++ b/supervisor/tests/test_supervisord.py @@ -390,6 +390,7 @@ def make_pconfig(name, command, **params): 'stopasgroup': False, 'killasgroup': False, 'exitcodes': (0,), 'environment': None, 'serverurl': None, + 'loglevel': 'info', 'logformat': '{message}', 'logformatter': 'plaintext' } result.update(params) return ProcessConfig(options, **result) @@ -459,6 +460,7 @@ def make_pconfig(name, command, **params): 'stopasgroup': False, 'killasgroup': False, 'exitcodes': (0,), 'environment': None, 'serverurl': None, + 'loglevel': 'info', 'logformat': '{message}', 'logformatter': 'plaintext' } result.update(params) return EventListenerConfig(options, **result) @@ -840,4 +842,3 @@ def test_suite(): if __name__ == '__main__': unittest.main(defaultTest='test_suite') -