diff --git a/.github/workflows/main.yml b/.github/workflows/main.yml index e19a90a71..4614acd2e 100644 --- a/.github/workflows/main.yml +++ b/.github/workflows/main.yml @@ -9,7 +9,7 @@ env: jobs: tests_py27: - runs-on: ubuntu-20.04 + runs-on: ubuntu-24.04 container: python:2.7 strategy: fail-fast: false @@ -26,93 +26,12 @@ jobs: - name: Run the end-to-end tests run: TOXENV=py27 END_TO_END=1 tox - tests_py34: - runs-on: ubuntu-20.04 - strategy: - fail-fast: false - - steps: - - uses: actions/checkout@v4 - - - name: Build OpenSSL 1.0.2 (required by Python 3.4) - run: | - sudo apt-get install build-essential zlib1g-dev - - cd $RUNNER_TEMP - wget https://github.com/openssl/openssl/releases/download/OpenSSL_1_0_2u/openssl-1.0.2u.tar.gz - tar -xf openssl-1.0.2u.tar.gz - cd openssl-1.0.2u - ./config --prefix=/usr/local/ssl --openssldir=/usr/local/ssl shared zlib-dynamic - make - sudo make install - - echo CFLAGS="-I/usr/local/ssl/include $CFLAGS" >> $GITHUB_ENV - echo LDFLAGS="-L/usr/local/ssl/lib $LDFLAGS" >> $GITHUB_ENV - echo LD_LIBRARY_PATH="/usr/local/ssl/lib:$LD_LIBRARY_PATH" >> $GITHUB_ENV - - sudo ln -s /usr/local/ssl/lib/libssl.so.1.0.0 /usr/lib/libssl.so.1.0.0 - sudo ln -s /usr/local/ssl/lib/libcrypto.so.1.0.0 /usr/lib/libcrypto.so.1.0.0 - sudo ldconfig - - - name: Build Python 3.4 - run: | - sudo apt-get install build-essential libncurses5-dev libgdbm-dev libnss3-dev libreadline-dev zlib1g-dev - - cd $RUNNER_TEMP - wget -O cpython-3.4.10.zip https://github.com/python/cpython/archive/refs/tags/v3.4.10.zip - unzip cpython-3.4.10.zip - cd cpython-3.4.10 - ./configure - make - sudo make install - - python3.4 --version - python3.4 -c 'import ssl' - - - name: Install dependencies - run: $PIP install virtualenv==20.4.7 tox==3.28.0 - - - name: Run the unit tests - run: TOXENV=py34 tox - - - name: Run the end-to-end tests - run: TOXENV=py34 END_TO_END=1 tox - - tests_py35: - runs-on: ubuntu-20.04 - strategy: - fail-fast: false - - steps: - - uses: actions/checkout@v4 - - - name: Work around pip SSL cert verify error - run: sudo $PIP config set global.trusted-host 'pypi.python.org pypi.org files.pythonhosted.org' - - - name: Set up Python 3.5 - uses: actions/setup-python@v5 - with: - python-version: 3.5 - - - name: Install dependencies - run: $PIP install virtualenv tox - - - name: Set variable for TOXENV based on Python version - id: toxenv - run: python -c 'import sys; print("TOXENV=py%d%d" % (sys.version_info.major, sys.version_info.minor))' | tee -a $GITHUB_OUTPUT - - - name: Run the unit tests - run: TOXENV=${{steps.toxenv.outputs.TOXENV}} tox - - - name: Run the end-to-end tests - run: TOXENV=${{steps.toxenv.outputs.TOXENV}} END_TO_END=1 tox - tests_py3x: - runs-on: ubuntu-20.04 + runs-on: ubuntu-24.04 strategy: fail-fast: false matrix: - python-version: [3.6, 3.7, 3.8, 3.9, "3.10", 3.11, 3.12, 3.13] + python-version: [3.7.1, 3.8, 3.9, "3.10", 3.11, 3.12, 3.13] steps: - uses: actions/checkout@v4 @@ -136,7 +55,7 @@ jobs: run: TOXENV=${{steps.toxenv.outputs.TOXENV}} END_TO_END=1 tox coverage_py27: - runs-on: ubuntu-20.04 + runs-on: ubuntu-24.04 container: python:2.7 strategy: fail-fast: false @@ -151,7 +70,7 @@ jobs: run: TOXENV=cover tox coverage_py3x: - runs-on: ubuntu-20.04 + runs-on: ubuntu-24.04 strategy: fail-fast: false matrix: @@ -172,7 +91,7 @@ jobs: run: TOXENV=cover3 tox docs: - runs-on: ubuntu-20.04 + runs-on: ubuntu-24.04 steps: - uses: actions/checkout@v4 diff --git a/docs/configuration.rst b/docs/configuration.rst index 9029c2b4d..7a78cb846 100644 --- a/docs/configuration.rst +++ b/docs/configuration.rst @@ -301,6 +301,35 @@ follows. *Introduced*: 3.0 +``logfile_format`` + + The format string used for entries in the main supervisord activity log. + This uses Python's `logging format strings `_. + Available fields include ``%(asctime)s`` (timestamp), ``%(levelname)s`` + (log level), ``%(message)s`` (log message), ``%(process)d`` (process ID), + ``%(name)s`` (logger name), and other standard Python logging attributes. + + *Default*: ``%(asctime)s %(levelname)s %(message)s`` + + *Required*: No. + + *Introduced*: 4.3.0 + +``childlog_format`` + + The format string used for entries in child process log files (stdout/stderr). + This uses Python's `logging format strings `_. + Available fields include ``%(asctime)s`` (timestamp), ``%(message)s`` + (the actual output from the child process), ``%(name)s`` (logger name), + and other standard Python logging attributes. Note that ``%(levelname)s`` + and ``%(process)d`` refer to the supervisord process, not the child process. + + *Default*: ``%(message)s`` + + *Required*: No. + + *Introduced*: 4.3.0 + ``pidfile`` The location in which supervisord keeps its pid file. This option @@ -485,6 +514,8 @@ follows. logfile_maxbytes = 50MB logfile_backups=10 loglevel = info + logfile_format = %(asctime)s %(levelname)s %(message)s + childlog_format = %(message)s pidfile = /tmp/supervisord.pid nodaemon = false minfds = 1024 @@ -930,6 +961,13 @@ where specified. that is not seekable, log rotation must be disabled by setting ``stdout_logfile_maxbytes = 0``. + .. note:: + + The format of entries written to the stdout log file is controlled + by the ``childlog_format`` option in the ``[supervisord]`` section. + By default, only the raw output from the child process is logged, + but you can customize it to include timestamps and other information. + *Default*: ``AUTO`` *Required*: No. @@ -990,6 +1028,8 @@ where specified. ``stdout_syslog`` If true, stdout will be directed to syslog along with the process name. + The format of syslog entries is controlled by the ``childlog_format`` + option in the ``[supervisord]`` section, prefixed with the process name. *Default*: False @@ -1015,6 +1055,13 @@ where specified. that is not seekable, log rotation must be disabled by setting ``stderr_logfile_maxbytes = 0``. + .. note:: + + The format of entries written to the stderr log file is controlled + by the ``childlog_format`` option in the ``[supervisord]`` section. + By default, only the raw output from the child process is logged, + but you can customize it to include timestamps and other information. + *Default*: ``AUTO`` *Required*: No. @@ -1073,6 +1120,8 @@ where specified. ``stderr_syslog`` If true, stderr will be directed to syslog along with the process name. + The format of syslog entries is controlled by the ``childlog_format`` + option in the ``[supervisord]`` section, prefixed with the process name. *Default*: False diff --git a/supervisor/dispatchers.py b/supervisor/dispatchers.py index 0718a5868..34f38cf09 100644 --- a/supervisor/dispatchers.py +++ b/supervisor/dispatchers.py @@ -105,7 +105,13 @@ def __init__(self, process, event_type, fd): self.endtoken_data = (endtoken, len(endtoken)) self.mainlog_level = loggers.LevelsByName.DEBG config = self.process.config - self.log_to_mainlog = config.options.loglevel <= self.mainlog_level + # Handle case where options haven't been realized yet + loglevel = getattr(config.options, 'loglevel', None) + if loglevel is None: + # Default loglevel when not set + from supervisor.loggers import LevelsByName + loglevel = LevelsByName.INFO + self.log_to_mainlog = loglevel <= self.mainlog_level self.stdout_events_enabled = config.stdout_events_enabled self.stderr_events_enabled = config.stderr_events_enabled @@ -126,19 +132,26 @@ def _init_normallog(self): self.normallog = config.options.getLogger() if logfile: + fmt = getattr(config.options, 'childlog_format', None) + if fmt is None: + fmt = '%(message)s' # Default format loggers.handle_file( self.normallog, filename=logfile, - fmt='%(message)s', + fmt=fmt, rotating=not not maxbytes, # optimization maxbytes=maxbytes, backups=backups ) if to_syslog: + childlog_format = getattr(config.options, 'childlog_format', None) + if childlog_format is None: + childlog_format = '%(message)s' # Default format + fmt = config.name + ' ' + childlog_format loggers.handle_syslog( self.normallog, - fmt=config.name + ' %(message)s' + fmt=fmt ) def _init_capturelog(self): diff --git a/supervisor/loggers.py b/supervisor/loggers.py index 44d14b44c..df26fda24 100644 --- a/supervisor/loggers.py +++ b/supervisor/loggers.py @@ -153,9 +153,12 @@ class FileHandler(Handler): """File handler which supports reopening of logs. """ - def __init__(self, filename, mode='ab'): + def __init__(self, filename, mode='ab', fmt=None): Handler.__init__(self) + if fmt is not None: + self.setFormat(fmt) + try: self.stream = open(filename, mode) except OSError as e: @@ -187,7 +190,7 @@ def remove(self): class RotatingFileHandler(FileHandler): def __init__(self, filename, mode='ab', maxBytes=512*1024*1024, - backupCount=10): + backupCount=10, fmt=None): """ Open the specified file and use it as the stream for logging. @@ -210,7 +213,7 @@ def __init__(self, filename, mode='ab', maxBytes=512*1024*1024, """ if maxBytes > 0: mode = 'ab' # doesn't make sense otherwise! - FileHandler.__init__(self, filename, mode) + FileHandler.__init__(self, filename, mode, fmt) self.maxBytes = maxBytes self.backupCount = backupCount self.counter = 0 @@ -292,8 +295,17 @@ def asdict(self): msg = as_string(self.msg) if self.kw: msg = msg % self.kw - self.dictrepr = {'message':msg, 'levelname':levelname, - 'asctime':asctime} + self.dictrepr = { + 'message': msg, + 'levelname': levelname, + 'asctime': asctime, + 'levelno': self.level, + 'process': os.getpid(), + 'processName': 'supervisord', + 'threadName': 'MainThread' + } + self.dictrepr.update(self.kw) + return self.dictrepr class Logger: @@ -379,8 +391,18 @@ def emit(self, record): except: self.handleError() -def getLogger(level=None): - return Logger(level) +def getLogger(level=None, fmt=None): + logger = Logger(level) + if fmt is not None: + # Create a handler with the specified format + handler = StreamHandler() + handler.setFormat(fmt) + if level is not None: + handler.setLevel(level) + else: + handler.setLevel(logger.level) + logger.addHandler(handler) + return logger _2MB = 1<<21 @@ -400,6 +422,13 @@ def handle_stdout(logger, fmt): handler.setLevel(logger.level) logger.addHandler(handler) +def handle_stderr(logger, fmt): + """Attach a new StreamHandler with stderr handler to an existing Logger""" + handler = StreamHandler(sys.stderr) + handler.setFormat(fmt) + handler.setLevel(logger.level) + logger.addHandler(handler) + def handle_syslog(logger, fmt): """Attach a new Syslog handler to an existing Logger""" handler = SyslogHandler() @@ -413,10 +442,28 @@ def handle_file(logger, filename, fmt, rotating=False, maxbytes=0, backups=0): if filename == 'syslog': # TODO remove this handler = SyslogHandler() else: - if rotating is False: - handler = FileHandler(filename) - else: - handler = RotatingFileHandler(filename, 'a', maxbytes, backups) - handler.setFormat(fmt) - handler.setLevel(logger.level) - logger.addHandler(handler) + if filename == 'stdout': + return handle_stdout(logger, fmt) + if filename == 'stderr': + return handle_stderr(logger, fmt) + if not os.path.exists(filename): + # touching the file + try: + open(filename, 'a').close() + except (IOError, OSError): + pass + try: + if rotating: + handler = RotatingFileHandler( + filename, + maxBytes=maxbytes, + backupCount=backups + ) + else: + handler = FileHandler(filename) + handler.setFormat(fmt) + handler.setLevel(logger.level) + logger.addHandler(handler) + return handler + except (IOError, OSError): + logger.error('Cannot open file %s for writing' % filename) diff --git a/supervisor/options.py b/supervisor/options.py index 271735200..01210c874 100644 --- a/supervisor/options.py +++ b/supervisor/options.py @@ -456,6 +456,12 @@ def __init__(self): self.add(None, None, "v", "version", self.version) self.add("nodaemon", "supervisord.nodaemon", "n", "nodaemon", flag=1, default=0) + self.add("logfile_format", "supervisord.logfile_format", + "", "logfile_format=", str, + default="%(asctime)s %(levelname)s %(message)s") + self.add("childlog_format", "supervisord.childlog_format", + "", "childlog_format=", str, + default="%(message)s") self.add("user", "supervisord.user", "u:", "user=") self.add("umask", "supervisord.umask", "m:", "umask=", octal_type, default='022') @@ -528,6 +534,31 @@ def realize(self, *arg, **kw): self.uid = uid self.gid = gid_for_uid(uid) + loglevel = self.loglevel + if loglevel is None: + loglevel = section.loglevel + + logfile_format = section.logfile_format + childlog_format = section.childlog_format + + # Configure the main logger + self.logger = loggers.getLogger(loglevel) + + if self.logfile: + logfile = self.logfile + else: + logfile = section.logfile + + if logfile: + loggers.handle_file( + self.logger, + logfile, + logfile_format, + rotating=True, + maxbytes=section.logfile_maxbytes, + backups=section.logfile_backups + ) + if not self.loglevel: self.loglevel = section.loglevel @@ -650,6 +681,11 @@ def get(opt, default, **kwargs): section.pidfile = existing_dirpath(get('pidfile', 'supervisord.pid')) section.identifier = get('identifier', 'supervisor') section.nodaemon = boolean(get('nodaemon', 'false')) + section.logfile_format = get('logfile_format', + '%(asctime)s %(levelname)s %(message)s', + do_expand=False) + section.childlog_format = get('childlog_format', '%(message)s', + do_expand=False) section.silent = boolean(get('silent', 'false')) tempdir = tempfile.gettempdir() diff --git a/supervisor/skel/sample.conf b/supervisor/skel/sample.conf index 289c9cb38..980f638e5 100644 --- a/supervisor/skel/sample.conf +++ b/supervisor/skel/sample.conf @@ -46,6 +46,17 @@ logfile=/tmp/supervisord.log ; main log file; default $CWD/supervisord.log logfile_maxbytes=50MB ; max main logfile bytes b4 rotation; default 50MB logfile_backups=10 ; # of main logfile backups; 0 means none, default 10 loglevel=info ; log level; default info; others: debug,warn,trace + +; Main supervisord log file format +; Format string for main log file - uses standard Python logging format strings +; Default: %(asctime)s %(levelname)s %(message)s +;logfile_format=%(asctime)s %(levelname)s %(message)s + +; Child process log file format +; Format string for child process logs - uses standard Python logging format strings +; Default: %(message)s +;childlog_format=%(message)s + pidfile=/tmp/supervisord.pid ; supervisord pidfile; default supervisord.pid nodaemon=false ; start in foreground if true; default false silent=false ; no logs to stdout if true; default false diff --git a/supervisor/tests/base.py b/supervisor/tests/base.py index f608b2bea..ae4da2333 100644 --- a/supervisor/tests/base.py +++ b/supervisor/tests/base.py @@ -89,6 +89,7 @@ def __init__(self): self.umaskset = None self.poller = DummyPoller(self) self.silent = False + self.childlog_format = '%(message)s' def getLogger(self, *args, **kw): logger = DummyLogger() diff --git a/supervisor/tests/test_dispatchers.py b/supervisor/tests/test_dispatchers.py index 92b43bad1..3c4268285 100644 --- a/supervisor/tests/test_dispatchers.py +++ b/supervisor/tests/test_dispatchers.py @@ -569,6 +569,47 @@ def test_close(self): dispatcher.close() # make sure we don't error if we try to close twice self.assertEqual(dispatcher.closed, True) + def test_custom_format_for_process_logs(self): + """Test custom format is applied to process logs""" + from supervisor.datatypes import boolean, logfile_name + from supervisor.options import ServerOptions + options = ServerOptions() # need real options to get a real logger + options.childlog_format = '%(asctime)s [%(levelname)s] %(message)s' + + config = DummyPConfig(options, 'process1', '/bin/process1', + stdout_logfile=logfile_name('/tmp/foo')) + process = DummyProcess(config) + dispatcher = self._makeOne(process) + + # Check that format is passed to logger + self.assertEqual(dispatcher.childlog.handlers[0].fmt, + '%(asctime)s [%(levelname)s] %(message)s') + + def test_different_formats_for_main_and_child_logs(self): + """Test different formats for main and child logs""" + from supervisor.datatypes import boolean, logfile_name + from supervisor.options import ServerOptions + options = ServerOptions() + options.logfile_format = '%(asctime)s MAIN: %(message)s' + options.childlog_format = '%(asctime)s CHILD: %(message)s' + + # Configure child process logs + config = DummyPConfig(options, 'process1', '/bin/process1', + stdout_logfile=logfile_name('/tmp/foo')) + process = DummyProcess(config) + dispatcher = self._makeOne(process) + + # Check that child format is used + self.assertEqual(dispatcher.childlog.handlers[0].fmt, + '%(asctime)s CHILD: %(message)s') + + # Configure a main log + from supervisor.loggers import getLogger + logger = getLogger(fmt=options.logfile_format) + + # Check that main format is used + self.assertEqual(logger.handlers[0].fmt, + '%(asctime)s MAIN: %(message)s') class PInputDispatcherTests(unittest.TestCase): def _getTargetClass(self): diff --git a/supervisor/tests/test_loggers.py b/supervisor/tests/test_loggers.py index a9ae297fd..4e3a42587 100644 --- a/supervisor/tests/test_loggers.py +++ b/supervisor/tests/test_loggers.py @@ -221,6 +221,32 @@ def test_emit_error(self): self.assertTrue(dummy_stderr.written.endswith(b'OSError\n'), dummy_stderr.written) + def test_format_applied_to_handler(self): + """Test that the format is correctly applied to the handler""" + from supervisor.loggers import FileHandler + custom_format = '%(asctime)s [%(levelname)s] %(message)s' + handler = FileHandler(self.filename, fmt=custom_format) + record = self._makeLogRecord("test message") + handler.emit(record) + handler.close() + with open(self.filename, 'r') as f: + content = f.read() + # Check that the format was applied - should have timestamp and level + import re + self.assertTrue(re.match(r'\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \[INFO\] test message', content)) + + def test_default_format_when_not_specified(self): + """Test default format when no format is specified""" + from supervisor.loggers import FileHandler + handler = FileHandler(self.filename) # No format specified + record = self._makeLogRecord("test message") + handler.emit(record) + handler.close() + with open(self.filename, 'r') as f: + content = f.read() + # Should just contain the message itself + self.assertEqual(content, "test message") + if os.path.exists('/dev/stdout'): StdoutTestsBase = FileHandlerTests else: diff --git a/supervisor/tests/test_options.py b/supervisor/tests/test_options.py index 4f3ff71de..437178dbc 100644 --- a/supervisor/tests/test_options.py +++ b/supervisor/tests/test_options.py @@ -3409,6 +3409,33 @@ def test_daemonize_notifies_poller_before_and_after_fork(self): instance.poller.before_daemonize.assert_called_once_with() instance.poller.after_daemonize.assert_called_once_with() + def test_default_log_format_options(self): + """Test that default log format options are set correctly""" + text = lstrip(''' + [supervisord] + logfile=/tmp/supervisord.log + ''') + instance = self._makeOne() + instance.configfile = StringIO(text) + instance.realize(args=[]) + options = instance.configroot.supervisord + self.assertEqual(options.logfile_format, '%(asctime)s %(levelname)s %(message)s') + self.assertEqual(options.childlog_format, '%(message)s') + + def test_parse_log_format_options(self): + """Test parsing log format options from config""" + text = lstrip(''' + [supervisord] + logfile=/tmp/supervisord.log + logfile_format=%(asctime)s [%(levelname)s] [PID:%(process)d] %(message)s + childlog_format=[%(asctime)s] %(message)s + ''') + instance = self._makeOne() + instance.configfile = StringIO(text) + instance.realize(args=[]) + options = instance.configroot.supervisord + self.assertEqual(options.logfile_format, '%(asctime)s [%(levelname)s] [PID:%(process)d] %(message)s') + self.assertEqual(options.childlog_format, '[%(asctime)s] %(message)s') class ProcessConfigTests(unittest.TestCase): def _getTargetClass(self): from supervisor.options import ProcessConfig