From 5c94a6986e2cd9b45a09165b91a4669fa114ab26 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Tue, 20 Apr 2021 03:26:39 +0300
Subject: [PATCH 01/20] Adding plaintext and JSON logging formatters

---
 supervisor/dispatchers.py |   8 +-
 supervisor/loggers.py     | 233 +++++++++++++++++++++++++++++++++-----
 supervisor/options.py     |  32 +++++-
 3 files changed, 240 insertions(+), 33 deletions(-)

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/loggers.py b/supervisor/loggers.py
index 44d14b44c..a28c1ec3d 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -12,11 +12,18 @@
 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 pythonjsonlogger import jsonlogger
+from string import Template
+from string import Formatter as StrFormatter
+
 
 class LevelsByName:
     CRIT = 50   # messages that probably require immediate user attention
@@ -44,21 +51,175 @@ 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 = "%(asctime)s %(levelname)s %(message)s"
+_STYLES = {
+    '%': (PercentStyle, BASIC_FORMAT),
+    '$': (StringTemplateStyle, '${asctim} ${levelname} ${message}'),
+    '{': (StrFormatStyle, '{asctim} {levelname} {message}')
+}
+
+class PlainTextFormatter(logging.Formatter):
+    def format(self, record):
+        record.message = record.getMessage().rstrip('\n')
+        if self.usesTime():
+            record.asctime = self.formatTime(record, self.datefmt)
+        return self.formatMessage(record)
+
+class CustomJsonFormatter(jsonlogger.JsonFormatter):
+    def __init__(self, *args, **kwargs):
+        """Constructor."""
+        super().__init__(*args, **kwargs)
+        reserved_attrs = ('level', 'levelname', 'msg', 'kw', 'dictrepr', 'created', 'msecs')
+        reserved_attrs_dict = dict(zip(reserved_attrs, reserved_attrs))
+        self._skip_fields.update(reserved_attrs_dict)
+
+    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"""
+        message_dict = {}
+        if isinstance(record.msg, dict):
+            message_dict = record.msg
+            record.message = None
+        else:
+            message = record.getMessage()
+            try:
+                message_dict = json.loads(message)
+                record.message = None
+            except json.decoder.JSONDecodeError:
+                record.message = 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)
+
+def _formatter_factory(name=None, fmt=None, style=None):
+    if name is None:
+        name = 'plaintext'
+
+    if fmt is None:
+        fmt = '%(asctime)s %(levelname)s %(message)s'
+
+    if style is None:
+        style = None
+        # determine the style based on the logging format.
+        for style in _STYLES:
+            _style = _STYLES[style][0](fmt)
+            try:
+                _style.validate()
+                break # exit the loop if fmt passes style validation
+            except ValueError:
+                style = None
+
+    if style is None:
+        raise ValueError('Invalid logging format: %s' % fmt)
+
+    if name == 'plaintext':
+        return PlainTextFormatter(fmt, style=style)
+    elif name == 'json':
+        return CustomJsonFormatter(fmt, style=style)
+    else:
+        raise ValueError('Invalid formatter name: %s' % name)
+
+BASIC_FORMATTER = _formatter_factory(name='plaintext', fmt=BASIC_FORMAT)
+
 class Handler:
-    fmt = '%(message)s'
     level = LevelsByName.INFO
 
     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
@@ -87,17 +248,10 @@ def close(self):
             self.closed = True
 
     def emit(self, record):
+        raise NotImplementedError('emit must be implemented by Handler subclasses')
+
+    def write(self, msg):
         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')
             try:
                 self.stream.write(msg)
             except UnicodeError:
@@ -116,6 +270,8 @@ def handleError(self):
         del ei
 
 class StreamHandler(Handler):
+    terminator = '\n'
+
     def __init__(self, strm=None):
         Handler.__init__(self, strm)
 
@@ -126,6 +282,10 @@ def remove(self):
     def reopen(self):
         pass
 
+    def emit(self, record):
+        msg = self.formatter.format(record)
+        self.write(msg + self.terminator)
+
 class BoundIO:
     def __init__(self, maxbytes, buf=b''):
         self.maxbytes = maxbytes
@@ -152,6 +312,7 @@ def clear(self):
 class FileHandler(Handler):
     """File handler which supports reopening of logs.
     """
+    terminator = '\n'
 
     def __init__(self, filename, mode='ab'):
         Handler.__init__(self)
@@ -185,6 +346,15 @@ def remove(self):
             if why.args[0] != errno.ENOENT:
                 raise
 
+    def emit(self, record):
+        msg = self.formatter.format(record)
+        if 'b' in self.mode:
+            msg = bytes(msg, 'utf-8')
+            bytes_terminator = bytes(self.terminator, 'utf-8')
+            self.write(msg + bytes_terminator)
+        else:
+            self.write(msg + self.terminator)
+
 class RotatingFileHandler(FileHandler):
     def __init__(self, filename, mode='ab', maxBytes=512*1024*1024,
                  backupCount=10):
@@ -278,15 +448,18 @@ def doRollover(self):
 class LogRecord:
     def __init__(self, level, msg, **kw):
         self.level = level
-        self.msg = msg
+        self.levelname = LOG_LEVELS_BY_NUM[level]
+        self.msg = msg if isinstance(msg, str) else msg.decode('utf-8')
         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,6 +469,9 @@ def asdict(self):
                              'asctime':asctime}
         return self.dictrepr
 
+    def getMessage(self):
+        return self.msg
+
 class Logger:
     def __init__(self, level=None, handlers=None):
         if level is None:
@@ -371,7 +547,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 # BUG: this will break with the new foramtter.
                 try:
                     self._syslog(msg)
                 except UnicodeError:
@@ -384,30 +560,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 +596,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..5320eedac 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")        
+        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,12 @@ def realize(self, *arg, **kw):
         if not self.loglevel:
             self.loglevel = section.loglevel
 
+        if not self.logformat:
+            self.logformat = section.logformat
+
+        if not self.logformatter:
+            self.logformatter = section.logformatter
+
         if self.logfile:
             logfile = self.logfile
         else:
@@ -643,6 +654,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}')
+        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 +944,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', '{asctime} {levelname} {message}')
+        logformatter = get(section, 'logformatter', 'plaintext')
         if serverurl and serverurl.strip().upper() == 'AUTO':
             serverurl = None
 
@@ -1057,7 +1075,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 +1509,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 +1896,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):

From 88b38047fcc0507980108bc42b30618ff71cdaa8 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Tue, 20 Apr 2021 23:15:30 +0300
Subject: [PATCH 02/20] putting formatter creation logic in a class

---
 supervisor/loggers.py | 57 +++++++++++++++++++++++--------------------
 1 file changed, 30 insertions(+), 27 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index a28c1ec3d..b8c0109c5 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -178,34 +178,37 @@ def format(self, record):
         log_record = self.process_log_record(log_record)
         return self.serialize_log_record(log_record)
 
-def _formatter_factory(name=None, fmt=None, style=None):
-    if name is None:
-        name = 'plaintext'
-
-    if fmt is None:
-        fmt = '%(asctime)s %(levelname)s %(message)s'
-
-    if style is None:
-        style = None
-        # determine the style based on the logging format.
-        for style in _STYLES:
-            _style = _STYLES[style][0](fmt)
-            try:
-                _style.validate()
-                break # exit the loop if fmt passes style validation
-            except ValueError:
-                style = None
-
-    if style is None:
-        raise ValueError('Invalid logging format: %s' % fmt)
-
-    if name == 'plaintext':
-        return PlainTextFormatter(fmt, style=style)
-    elif name == 'json':
-        return CustomJsonFormatter(fmt, style=style)
-    else:
-        raise ValueError('Invalid formatter name: %s' % name)
 
+class FormatterFacotry:
+    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'
+
+        if style is None:
+            style = None
+            # determine the style based on the logging format.
+            for style in _STYLES:
+                _style = _STYLES[style][0](fmt)
+                try:
+                    _style.validate()
+                    break # exit the loop if fmt passes style validation
+                except ValueError:
+                    style = None
+
+        if style is None:
+            raise ValueError('Invalid logging format: %s' % fmt)
+
+        if name == 'plaintext':
+            return PlainTextFormatter(fmt, style=style)
+        elif name == 'json':
+            return CustomJsonFormatter(fmt, style=style)
+        else:
+            raise ValueError('Invalid formatter name: %s' % name)
+
+_formatter_factory = FormatterFacotry().get_formatter
 BASIC_FORMATTER = _formatter_factory(name='plaintext', fmt=BASIC_FORMAT)
 
 class Handler:

From 62ace158a257330ed68c65310940110078f0e1df Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 21 Apr 2021 04:07:00 +0300
Subject: [PATCH 03/20] Adding the ability to add default values for required
 fields in the logformat

---
 supervisor/loggers.py | 54 ++++++++++++++++++++++++++++++++-----------
 1 file changed, 41 insertions(+), 13 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index b8c0109c5..54769d33f 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -115,7 +115,13 @@ def validate(self):
 }
 
 class PlainTextFormatter(logging.Formatter):
+    def __init__(self, *args, **kwargs):
+        """Constructor."""
+        self.fields_with_default_value = kwargs.pop('fields_with_default_value', {})
+        super().__init__(*args, **kwargs)
+    
     def format(self, record):
+        record.__dict__.update(self.fields_with_default_value)
         record.message = record.getMessage().rstrip('\n')
         if self.usesTime():
             record.asctime = self.formatTime(record, self.datefmt)
@@ -124,6 +130,7 @@ def format(self, record):
 class CustomJsonFormatter(jsonlogger.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')
         reserved_attrs_dict = dict(zip(reserved_attrs, reserved_attrs))
@@ -153,6 +160,7 @@ def serialize_log_record(self, log_record):
 
     def format(self, record):
         """Formats a log record and serializes to json"""
+        record.__dict__.update(self.fields_with_default_value)
         message_dict = {}
         if isinstance(record.msg, dict):
             message_dict = record.msg
@@ -187,27 +195,47 @@ def get_formatter(self, name=None, fmt=None, style=None):
         if fmt is None:
             fmt = '%(asctime)s %(levelname)s %(message)s'
 
-        if style is None:
-            style = None
-            # determine the style based on the logging format.
-            for style in _STYLES:
-                _style = _STYLES[style][0](fmt)
-                try:
-                    _style.validate()
-                    break # exit the loop if fmt passes style validation
-                except ValueError:
-                    style = None
+        fmt, fields_with_default_value = self.get_fields_default_values(fmt)
 
         if style is None:
-            raise ValueError('Invalid logging format: %s' % fmt)
+            style = self.get_logformat_style(fmt)
 
         if name == 'plaintext':
-            return PlainTextFormatter(fmt, style=style)
+            return PlainTextFormatter(fmt, style=style, fields_with_default_value=fields_with_default_value)
         elif name == 'json':
-            return CustomJsonFormatter(fmt, style=style)
+            return CustomJsonFormatter(fmt, style=style, fields_with_default_value=fields_with_default_value)
         else:
             raise ValueError('Invalid formatter name: %s' % name)
 
+    def get_logformat_style(self, fmt):
+        """Determine the string format style based on the logformat."""
+        style = None
+        for style in _STYLES:
+            _style = _STYLES[style][0](fmt)
+            try:
+                _style.validate()
+                break # exit the loop if fmt passes style validation
+            except ValueError:
+                style = None
+
+        if style is None:
+            raise ValueError('Invalid logging format: %s' % fmt)
+
+        return style
+
+    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 = FormatterFacotry().get_formatter
 BASIC_FORMATTER = _formatter_factory(name='plaintext', fmt=BASIC_FORMAT)
 

From 67c6c7f94c707cc418325ae2490022af7f4d4c9f Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 21 Apr 2021 05:09:18 +0300
Subject: [PATCH 04/20] Avoid overwriting record fields with default values.

---
 supervisor/loggers.py | 17 ++++++++++++++---
 1 file changed, 14 insertions(+), 3 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 54769d33f..359d012a9 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -119,9 +119,14 @@ def __init__(self, *args, **kwargs):
         """Constructor."""
         self.fields_with_default_value = kwargs.pop('fields_with_default_value', {})
         super().__init__(*args, **kwargs)
-    
+
     def format(self, record):
-        record.__dict__.update(self.fields_with_default_value)
+        # 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().rstrip('\n')
         if self.usesTime():
             record.asctime = self.formatTime(record, self.datefmt)
@@ -160,7 +165,13 @@ def serialize_log_record(self, log_record):
 
     def format(self, record):
         """Formats a log record and serializes to json"""
-        record.__dict__.update(self.fields_with_default_value)
+        # 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.__dict__ = _record
         message_dict = {}
         if isinstance(record.msg, dict):
             message_dict = record.msg

From 5f1b906ba80990c3113c06c20fdfed86eb09a9bb Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 21 Apr 2021 07:27:36 +0300
Subject: [PATCH 05/20] Adding the only supervisor dependency:
 python-json-logger

---
 setup.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/setup.py b/setup.py
index dd87f7d06..a1610294a 100644
--- a/setup.py
+++ b/setup.py
@@ -22,7 +22,7 @@
 elif (3, 0) < py_version < (3, 4):
     raise RuntimeError('On Python 3, Supervisor requires Python 3.4 or later')
 
-requires = []
+requires = ["python-json-logger==2.0.1"]
 tests_require = []
 if py_version < (3, 3):
     tests_require.append('mock<4.0.0.dev0')

From 45803b74f972bfee1be942bf356c02941ced2520 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 21 Apr 2021 08:50:02 +0300
Subject: [PATCH 06/20] Adding log attributes to DummyPConfig object

---
 supervisor/tests/base.py | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/supervisor/tests/base.py b/supervisor/tests/base.py
index bef82e964..3001dec25 100644
--- a/supervisor/tests/base.py
+++ b/supervisor/tests/base.py
@@ -520,7 +520,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 +557,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"]

From 30ab58f5622ad94a471a408fe3733368e2965322 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 21 Apr 2021 20:43:53 +0300
Subject: [PATCH 07/20] Adding logging formatters options tests

---
 supervisor/tests/test_options.py | 13 +++++++++++++
 1 file changed, 13 insertions(+)

diff --git a/supervisor/tests/test_options.py b/supervisor/tests/test_options.py
index 5c9a35f6d..ef93a334a 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]
@@ -605,6 +615,9 @@ def test_options(self):
         self.assertEqual(proc2.stdout_logfile_backups, 2)
         self.assertEqual(proc2.exitcodes, [0])
         self.assertEqual(proc2.directory, None)
+        self.assertEqual(proc2.loglevel, 40)
+        self.assertEqual(proc2.logformat, '{message}')
+        self.assertEqual(proc2.logformatter, 'plaintext')
 
         cat3 = options.process_group_configs[2]
         self.assertEqual(cat3.name, 'cat3')

From f8e4f93ed8fb0519a7764402b5e2a7d7ff83631b Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 21 Apr 2021 23:51:23 +0300
Subject: [PATCH 08/20] Adding the ability to set level by description

---
 supervisor/loggers.py | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 359d012a9..028347539 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -518,6 +518,9 @@ class Logger:
     def __init__(self, level=None, handlers=None):
         if level is None:
             level = LevelsByName.INFO
+        elif isinstance(level, str):
+            level = getLevelNumByDescription(level)
+        assert(isinstance(level, LevelsByName))
         self.level = level
 
         if handlers is None:

From f52b2e2fa518f1e0df9272dc7d21bba55d06a207 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 22 Apr 2021 00:05:15 +0300
Subject: [PATCH 09/20] Adding the ability to set level by number

---
 supervisor/loggers.py | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 028347539..b7c4c2e93 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -520,6 +520,9 @@ def __init__(self, level=None, handlers=None):
             level = LevelsByName.INFO
         elif isinstance(level, str):
             level = getLevelNumByDescription(level)
+        elif isinstance(level, int):
+            levelname = LOG_LEVELS_BY_NUM[level]
+            level = getLevelNumByDescription(levelname)
         assert(isinstance(level, LevelsByName))
         self.level = level
 

From 646f19dc2ed3dbd2ed5329d74a649d0b33b2c185 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 22 Apr 2021 02:31:46 +0300
Subject: [PATCH 10/20] Reverting commit
 f52b2e2fa518f1e0df9272dc7d21bba55d06a207

---
 supervisor/loggers.py | 4 ----
 1 file changed, 4 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index b7c4c2e93..8465ab66e 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -520,10 +520,6 @@ def __init__(self, level=None, handlers=None):
             level = LevelsByName.INFO
         elif isinstance(level, str):
             level = getLevelNumByDescription(level)
-        elif isinstance(level, int):
-            levelname = LOG_LEVELS_BY_NUM[level]
-            level = getLevelNumByDescription(levelname)
-        assert(isinstance(level, LevelsByName))
         self.level = level
 
         if handlers is None:

From a3bb1d1fd2eaf87f356c34c9d0f6905fc894b4c4 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 22 Apr 2021 02:44:16 +0300
Subject: [PATCH 11/20] Removing unintended unit testing

---
 supervisor/tests/test_options.py | 9 ---------
 1 file changed, 9 deletions(-)

diff --git a/supervisor/tests/test_options.py b/supervisor/tests/test_options.py
index ef93a334a..22561727f 100644
--- a/supervisor/tests/test_options.py
+++ b/supervisor/tests/test_options.py
@@ -544,9 +544,6 @@ def test_options(self):
         self.assertEqual(options.logfile, 'supervisord.log')
         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)
@@ -590,9 +587,6 @@ 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]
@@ -615,9 +609,6 @@ def test_options(self):
         self.assertEqual(proc2.stdout_logfile_backups, 2)
         self.assertEqual(proc2.exitcodes, [0])
         self.assertEqual(proc2.directory, None)
-        self.assertEqual(proc2.loglevel, 40)
-        self.assertEqual(proc2.logformat, '{message}')
-        self.assertEqual(proc2.logformatter, 'plaintext')
 
         cat3 = options.process_group_configs[2]
         self.assertEqual(cat3.name, 'cat3')

From 771e101a9c6d7391b9f9e8d0d9a691f033d9187b Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 22 Apr 2021 04:36:38 +0300
Subject: [PATCH 12/20] Fxing a typo

---
 supervisor/loggers.py | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 8465ab66e..b225d9069 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -198,7 +198,7 @@ def format(self, record):
         return self.serialize_log_record(log_record)
 
 
-class FormatterFacotry:
+class FormatterFactory:
     def get_formatter(self, name=None, fmt=None, style=None):
         if name is None:
             name = 'plaintext'
@@ -247,7 +247,7 @@ def get_fields_default_values(self, fmt):
         return fmt, fields_with_default_value
 
 
-_formatter_factory = FormatterFacotry().get_formatter
+_formatter_factory = FormatterFactory().get_formatter
 BASIC_FORMATTER = _formatter_factory(name='plaintext', fmt=BASIC_FORMAT)
 
 class Handler:

From 9fbe7e6a48f0fe7437ed147b9d8f13d30b6ca7b1 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 22 Apr 2021 05:02:03 +0300
Subject: [PATCH 13/20] Using for/else for simplicity

---
 supervisor/loggers.py | 8 ++------
 1 file changed, 2 insertions(+), 6 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index b225d9069..4b69d2ce9 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -220,20 +220,16 @@ def get_formatter(self, name=None, fmt=None, style=None):
 
     def get_logformat_style(self, fmt):
         """Determine the string format style based on the logformat."""
-        style = None
         for style in _STYLES:
             _style = _STYLES[style][0](fmt)
             try:
                 _style.validate()
-                break # exit the loop if fmt passes style validation
+                return style # return style if fmt passes style validation
             except ValueError:
                 style = None
-
-        if style is None:
+        else:
             raise ValueError('Invalid logging format: %s' % fmt)
 
-        return style
-
     def get_fields_default_values(self, fmt):
         fields_with_default_value = {}
         placeholder_pattern = re.compile(r'[\{\(](.+?)[\}\)]', re.IGNORECASE)

From 29fcd9a840fc88ec422a29aee4ae695556d3f459 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 22 Apr 2021 05:05:28 +0300
Subject: [PATCH 14/20] Refactoring formatters factory conditionals

---
 supervisor/loggers.py | 5 ++---
 1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 4b69d2ce9..65d30e9fd 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -213,10 +213,9 @@ def get_formatter(self, name=None, fmt=None, style=None):
 
         if name == 'plaintext':
             return PlainTextFormatter(fmt, style=style, fields_with_default_value=fields_with_default_value)
-        elif name == 'json':
+        if name == 'json':
             return CustomJsonFormatter(fmt, style=style, fields_with_default_value=fields_with_default_value)
-        else:
-            raise ValueError('Invalid formatter name: %s' % name)
+        raise ValueError('Invalid formatter name: %s' % name)
 
     def get_logformat_style(self, fmt):
         """Determine the string format style based on the logformat."""

From 1f59e798c93c2e550650b0893bf34d4c931377e1 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 22 Apr 2021 05:06:14 +0300
Subject: [PATCH 15/20] Removing duplicate code

---
 supervisor/loggers.py | 1 -
 1 file changed, 1 deletion(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 65d30e9fd..12611dab0 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -171,7 +171,6 @@ def format(self, record):
         _record.update(record.__dict__)
         record.__dict__ = _record
 
-        record.__dict__ = _record
         message_dict = {}
         if isinstance(record.msg, dict):
             message_dict = record.msg

From 618b16ba1a1ec4721eda969cba2a8c714b9c05e5 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 28 Apr 2021 09:24:40 +0300
Subject: [PATCH 16/20] Code restructuring and CI tests updates

---
 supervisor/loggers.py                | 75 ++++++++++++++++++----------
 supervisor/options.py                |  8 +--
 supervisor/tests/base.py             |  5 +-
 supervisor/tests/test_options.py     | 17 ++++++-
 supervisor/tests/test_supervisord.py |  3 +-
 5 files changed, 75 insertions(+), 33 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 12611dab0..ecec039e9 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -20,9 +20,11 @@
 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 pythonjsonlogger import jsonlogger
 from string import Template
 from string import Formatter as StrFormatter
+from collections import OrderedDict
 
 
 class LevelsByName:
@@ -107,19 +109,31 @@ def validate(self):
         if not fields:
             raise ValueError('invalid format: no fields')
 
-BASIC_FORMAT = "%(asctime)s %(levelname)s %(message)s"
+BASIC_FORMAT = "%(message)s"
 _STYLES = {
     '%': (PercentStyle, BASIC_FORMAT),
-    '$': (StringTemplateStyle, '${asctim} ${levelname} ${message}'),
-    '{': (StrFormatStyle, '{asctim} {levelname} {message}')
+    '$': (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.
@@ -127,10 +141,12 @@ def format(self, record):
         _record.update(record.__dict__)
         record.__dict__ = _record
 
-        record.message = record.getMessage().rstrip('\n')
+        record.message = record.getMessage()
+
         if self.usesTime():
             record.asctime = self.formatTime(record, self.datefmt)
-        return self.formatMessage(record)
+
+        return self.formatMessage(record) + self.fmt_terminator
 
 class CustomJsonFormatter(jsonlogger.JsonFormatter):
     def __init__(self, *args, **kwargs):
@@ -140,6 +156,7 @@ def __init__(self, *args, **kwargs):
         reserved_attrs = ('level', 'levelname', 'msg', 'kw', 'dictrepr', 'created', 'msecs')
         reserved_attrs_dict = dict(zip(reserved_attrs, reserved_attrs))
         self._skip_fields.update(reserved_attrs_dict)
+        self.fmt_terminator = '\n'
 
     def parse(self):
         """
@@ -194,7 +211,7 @@ def format(self, record):
 
         self.add_fields(log_record, record, message_dict)
         log_record = self.process_log_record(log_record)
-        return self.serialize_log_record(log_record)
+        return self.serialize_log_record(log_record) + self.fmt_terminator
 
 
 class FormatterFactory:
@@ -226,7 +243,7 @@ def get_logformat_style(self, fmt):
             except ValueError:
                 style = None
         else:
-            raise ValueError('Invalid logging format: %s' % fmt)
+            raise ValueError('Invalid logging format: %s (%s)' % (fmt, type(fmt)))
 
     def get_fields_default_values(self, fmt):
         fields_with_default_value = {}
@@ -246,6 +263,7 @@ def get_fields_default_values(self, fmt):
 
 class Handler:
     level = LevelsByName.INFO
+    terminator = ''
 
     def __init__(self, stream=None):
         self.stream = stream
@@ -284,10 +302,8 @@ def close(self):
             self.closed = True
 
     def emit(self, record):
-        raise NotImplementedError('emit must be implemented by Handler subclasses')
-
-    def write(self, msg):
         try:
+            msg = self.formatter.format(record)
             try:
                 self.stream.write(msg)
             except UnicodeError:
@@ -295,7 +311,7 @@ def write(self, msg):
                 # 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()
@@ -306,7 +322,7 @@ def handleError(self):
         del ei
 
 class StreamHandler(Handler):
-    terminator = '\n'
+    terminator = ''
 
     def __init__(self, strm=None):
         Handler.__init__(self, strm)
@@ -318,10 +334,6 @@ def remove(self):
     def reopen(self):
         pass
 
-    def emit(self, record):
-        msg = self.formatter.format(record)
-        self.write(msg + self.terminator)
-
 class BoundIO:
     def __init__(self, maxbytes, buf=b''):
         self.maxbytes = maxbytes
@@ -337,7 +349,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
@@ -348,7 +360,7 @@ def clear(self):
 class FileHandler(Handler):
     """File handler which supports reopening of logs.
     """
-    terminator = '\n'
+    terminator = ''
 
     def __init__(self, filename, mode='ab'):
         Handler.__init__(self)
@@ -383,13 +395,19 @@ def remove(self):
                 raise
 
     def emit(self, record):
-        msg = self.formatter.format(record)
-        if 'b' in self.mode:
-            msg = bytes(msg, 'utf-8')
-            bytes_terminator = bytes(self.terminator, 'utf-8')
-            self.write(msg + bytes_terminator)
-        else:
-            self.write(msg + self.terminator)
+        try:
+            msg = self.formatter.format(record)
+            if 'b' in self.mode:
+                #msg = bytes(msg, 'utf-8')
+                #bytes_terminator = bytes(self.terminator, 'utf-8')
+                #self.stream.write(msg + bytes_terminator)
+                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,
@@ -485,7 +503,7 @@ class LogRecord:
     def __init__(self, level, msg, **kw):
         self.level = level
         self.levelname = LOG_LEVELS_BY_NUM[level]
-        self.msg = msg if isinstance(msg, str) else msg.decode('utf-8')
+        self.msg = as_string(msg)
         self.kw = kw
         self.dictrepr = None
         self.created = time.time()
@@ -514,6 +532,8 @@ def __init__(self, level=None, handlers=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:
@@ -566,6 +586,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"
 
@@ -585,7 +606,7 @@ def emit(self, record):
             message = params['message']
             for line in message.rstrip('\n').split('\n'):
                 params['message'] = line
-                msg = self.fmt % params # BUG: this will break with the new foramtter.
+                msg = self.fmt % params # TODO: Use parent Handler formatter.
                 try:
                     self._syslog(msg)
                 except UnicodeError:
diff --git a/supervisor/options.py b/supervisor/options.py
index 5320eedac..cc77cf8bf 100644
--- a/supervisor/options.py
+++ b/supervisor/options.py
@@ -434,7 +434,7 @@ def __init__(self):
         self.add("loglevel", "supervisord.loglevel", "e:", "loglevel=",
                  logging_level, default="info")
         self.add("logformat", "supervisord.logformat", 
-                 default="%(asctime)s %(levelname)s %(message)s")        
+                 default="%(asctime)s %(levelname)s %(message)s\n")
         self.add("logformatter", "supervisord.logformatter", 
                  default="plaintext")
         self.add("pidfile", "supervisord.pidfile", "j:", "pidfile=",
@@ -504,6 +504,8 @@ def realize(self, *arg, **kw):
 
         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
@@ -655,7 +657,7 @@ def get(opt, default, **kwargs):
         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}')
+        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')
@@ -946,7 +948,7 @@ def get(section, opt, *args, **kwargs):
         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', '{asctime} {levelname} {message}')
+        logformat = get(section, 'logformat', '{message}')
         logformatter = get(section, 'logformatter', 'plaintext')
         if serverurl and serverurl.strip().upper() == 'AUTO':
             serverurl = None
diff --git a/supervisor/tests/base.py b/supervisor/tests/base.py
index 3001dec25..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()
diff --git a/supervisor/tests/test_options.py b/supervisor/tests/test_options.py
index 22561727f..de8297930 100644
--- a/supervisor/tests/test_options.py
+++ b/supervisor/tests/test_options.py
@@ -544,6 +544,9 @@ def test_options(self):
         self.assertEqual(options.logfile, 'supervisord.log')
         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)
@@ -587,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]
@@ -3341,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)
 
@@ -3439,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)
 
@@ -3482,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')
-

From 959c928318867a0340eb91026205f253ab68765c Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 29 Apr 2021 02:12:48 +0300
Subject: [PATCH 17/20] Making the logger backward compatible

---
 supervisor/loggers.py | 14 ++++++++------
 1 file changed, 8 insertions(+), 6 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index ecec039e9..8e68e7e42 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -198,7 +198,7 @@ def format(self, record):
                 message_dict = json.loads(message)
                 record.message = None
             except json.decoder.JSONDecodeError:
-                record.message = message.rstrip('\n')
+                record.message = as_string(message).rstrip('\n')
 
         # only format time if needed
         if "asctime" in self._required_fields:
@@ -398,9 +398,6 @@ def emit(self, record):
         try:
             msg = self.formatter.format(record)
             if 'b' in self.mode:
-                #msg = bytes(msg, 'utf-8')
-                #bytes_terminator = bytes(self.terminator, 'utf-8')
-                #self.stream.write(msg + bytes_terminator)
                 msg = as_bytes(msg + self.terminator)
                 self.stream.write(msg)
             else:
@@ -503,7 +500,7 @@ class LogRecord:
     def __init__(self, level, msg, **kw):
         self.level = level
         self.levelname = LOG_LEVELS_BY_NUM[level]
-        self.msg = as_string(msg)
+        self.msg = msg
         self.kw = kw
         self.dictrepr = None
         self.created = time.time()
@@ -524,7 +521,12 @@ def asdict(self):
         return self.dictrepr
 
     def getMessage(self):
-        return self.msg
+        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)
 
 class Logger:
     def __init__(self, level=None, handlers=None):

From b573bd33e2e2d7e74800201194a495040dd7e797 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Thu, 29 Apr 2021 04:02:58 +0300
Subject: [PATCH 18/20] Removing jsonformatter dependency

---
 setup.py                    |   2 +-
 supervisor/jsonformatter.py | 227 ++++++++++++++++++++++++++++++++++++
 supervisor/loggers.py       |  17 +--
 3 files changed, 238 insertions(+), 8 deletions(-)
 create mode 100644 supervisor/jsonformatter.py

diff --git a/setup.py b/setup.py
index a1610294a..dd87f7d06 100644
--- a/setup.py
+++ b/setup.py
@@ -22,7 +22,7 @@
 elif (3, 0) < py_version < (3, 4):
     raise RuntimeError('On Python 3, Supervisor requires Python 3.4 or later')
 
-requires = ["python-json-logger==2.0.1"]
+requires = []
 tests_require = []
 if py_version < (3, 3):
     tests_require.append('mock<4.0.0.dev0')
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 8e68e7e42..df507c9ec 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -21,7 +21,7 @@
 from supervisor.compat import is_text_stream
 from supervisor.compat import as_string
 from supervisor.compat import as_bytes
-from pythonjsonlogger import jsonlogger
+from supervisor.jsonformatter import JsonFormatter
 from string import Template
 from string import Formatter as StrFormatter
 from collections import OrderedDict
@@ -148,7 +148,7 @@ def format(self, record):
 
         return self.formatMessage(record) + self.fmt_terminator
 
-class CustomJsonFormatter(jsonlogger.JsonFormatter):
+class CustomJsonFormatter(JsonFormatter):
     def __init__(self, *args, **kwargs):
         """Constructor."""
         self.fields_with_default_value = kwargs.pop('fields_with_default_value', {})
@@ -521,11 +521,14 @@ def asdict(self):
         return self.dictrepr
 
     def getMessage(self):
-        try:
-            return as_string(self.msg) % self.kw
-        except ValueError as e:
-            # Skip string interpolation when string
-            # formatting charcaters are not escaped.
+        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:

From b9cde7dcc4dcd8fb33a0bc1a31d2be1a4135052b Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Fri, 30 Apr 2021 02:56:19 +0300
Subject: [PATCH 19/20] loggers updates

---
 supervisor/loggers.py | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index df507c9ec..1fdd33a64 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -154,8 +154,7 @@ def __init__(self, *args, **kwargs):
         self.fields_with_default_value = kwargs.pop('fields_with_default_value', {})
         super().__init__(*args, **kwargs)
         reserved_attrs = ('level', 'levelname', 'msg', 'kw', 'dictrepr', 'created', 'msecs')
-        reserved_attrs_dict = dict(zip(reserved_attrs, reserved_attrs))
-        self._skip_fields.update(reserved_attrs_dict)
+        self._skip_fields.update((v, v) for v in reserved_attrs)
         self.fmt_terminator = '\n'
 
     def parse(self):

From 5736268f97e0ea6d4af07ffcb89348233996bb90 Mon Sep 17 00:00:00 2001
From: Hassan Alshehri <alshehri.hass@gmail.com>
Date: Wed, 5 May 2021 02:10:44 +0300
Subject: [PATCH 20/20] Fixing an issue where numbers are considered valid JSON
 by the praser

---
 supervisor/loggers.py | 11 +++++++++--
 1 file changed, 9 insertions(+), 2 deletions(-)

diff --git a/supervisor/loggers.py b/supervisor/loggers.py
index 1fdd33a64..2eb04f9b1 100644
--- a/supervisor/loggers.py
+++ b/supervisor/loggers.py
@@ -194,8 +194,15 @@ def format(self, record):
         else:
             message = record.getMessage()
             try:
-                message_dict = json.loads(message)
-                record.message = None
+                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')