Hello,

I have been chatting with Copilot AI for some days to get help investigating some logging-related issues in a Mailman 3.3.4 Docker installation and, so I would appreciate any guidance.

We are working on a long needed upgrade, but for now I need the logs in Elasticsearch, and they are aweful.

Environment

• GNU Mailman 3.3.4 (Tom Sawyer)
• Python 3.8.10
• Docker-based installation
• Test environment with a single mailing list: listname@example.com<mailto:listname@example.com>

Logging configuration

I've configured dedicated log files for most logging channels. For example, [logging.http] is configured with format: %(asctime)s (%(process)d) %(message)s, datefmt: %Y-%m-%d %H:%M:%S.%3N, propagate: no, level: debug, and path: http.log.

All [logging.*] sections in the generated /etc/mailman-extra.cfg use the same datefmt. format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: info path: mailman.log

[logging.archiver] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: archiver.log

[logging.bounce] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: bounce.log

[logging.config] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: config.log

[logging.database] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: database.log

[logging.debug] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: debug.log

[logging.error] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: error.log

[logging.fromusenet] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: fromusenet.log

[logging.http] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: http.log

[logging.locks] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: locks.log

[logging.mischief] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: mischief.log

[logging.plugins] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: plugins.log

[logging.runner] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: info path: runner.log

[logging.smtp] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: info path: smtp.log

[logging.smtp-failure] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: smtp-failure.log

[logging.subscribe] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: subscribe.log

[logging.vette] format: %(asctime)s (%(process)d) %(message)s datefmt: %Y-%m-%d %H:%M:%S.%3N propagate: no level: debug path: vette.log

Issue 1: Mixed log formats

Despite configuring all logging sections with datefmt: %Y-%m-%d %H:%M:%S.%3N, I still see multiple timestamp formats in mailman.log, for example:

• [30/Jul/2026:12:00:03 +0000] "GET /3.1/lists?count=10&page=1 HTTP/1.1" 200 90 "-" "GNU Mailman REST client v3.3.3"
• [2026-07-30 12:32:15 +0000] [36] [INFO] Shutting down: Master
• Jul 30 12:32:14 2026 (1) Master watcher caught SIGTERM. Exiting

This suggests that multiple logging systems may be writing to the same log file.

Issue 2: Runner debug noise

With logging level set to debug, mailman.log contains a large number of entries such as:

• Jul 31 07:58:12 2026 (33) [PipelineRunner] starting oneloop
• Jul 31 07:58:12 2026 (33) [PipelineRunner] ending oneloop: 0
• Jul 31 07:58:12 2026 (26) [ArchiveRunner] starting oneloop
• Jul 31 07:58:12 2026 (26) [ArchiveRunner] ending oneloop: 0
• Jul 31 07:58:12 2026 (29) [IncomingRunner] starting oneloop
• Jul 31 07:58:12 2026 (29) [IncomingRunner] ending oneloop: 0
• Jul 31 07:58:13 2026 (28) [CommandRunner] starting oneloop
• Jul 31 07:58:13 2026 (36) [VirginRunner] starting oneloop
• Jul 31 07:58:13 2026 (36) [VirginRunner] ending oneloop: 0
• Jul 31 07:58:13 2026 (28) [CommandRunner] ending oneloop: 0
• Jul 31 07:58:13 2026 (37) [DigestRunner] starting oneloop
• Jul 31 07:58:13 2026 (37) [DigestRunner] ending oneloop: 0
• Jul 31 07:58:13 2026 (31) [NNTPRunner] starting oneloop
• Jul 31 07:58:13 2026 (32) [OutgoingRunner] starting oneloop
• Jul 31 07:58:13 2026 (31) [NNTPRunner] ending oneloop: 0
• Jul 31 07:58:13 2026 (32) [OutgoingRunner] ending oneloop: 0

Is there a recommended way to suppress these internal runner loop messages while retaining useful operational logging?

Issue 3: HTTP request logging

I intentionally keep [logging.http] at level: debug because I want to see which REST endpoints are called. Examples:

• [2026-08-03 12:10:28 +0000] [51] [DEBUG] GET /3.1/lists/listname@example.com<mailto:/3.1/lists/listname@example.com>
• [2026-08-03 12:15:29 +0000] [52] [DEBUG] GET /3.1/lists/listname@example.com<mailto:/3.1/lists/listname@example.com>
• [2026-08-03 13:00:03 +0000] [53] [DEBUG] GET /3.1/lists

My goal is to keep these request entries.

Issue 4: Falcon tracebacks in http.log

The same http.log also contains Falcon tracebacks. One example is:

2026-08-03 12:10:29 [FALCON] [ERROR] GET /3.1/lists/listname@example.com/config<mailto:/3.1/lists/listname@example.com/config> => Traceback (most recent call last):

File "/usr/lib/python3.8/site-packages/sqlalchemy/engine/result.py", line 779, in _getter getter = self._metadata._getter

AttributeError: 'NoneType' object has no attribute '_getter'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):

File "/usr/lib/python3.8/site-packages/falcon/app.py", line 361, in call responder(req, resp, **params)

File "/usr/lib/python3.8/site-packages/mailman/rest/listconf.py", line 282, in on_get value = getter.get(self._mlist, attribute)

File "/usr/lib/python3.8/site-packages/mailman/rest/listconf.py", line 52, in get return sorted(aliases.aliases)

File "/usr/lib/python3.8/site-packages/mailman/model/mailinglist.py", line 565, in aliases for alias in aliases

File "/usr/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 100, in instances cursor.close()

File "/usr/lib/python3.8/site-packages/sqlalchemy/util/langhelpers.py", line 68, in exit compat.raise_(

File "/usr/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_ raise exception

File "/usr/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 58, in instances *[

File "/usr/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 59, in query_entity.row_processor(query, context, cursor)

File "/usr/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 4422, in row_processor _instance = loading._instance_processor(

File "/usr/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 421, in _instance_processor getter = result._getter(col, False)

File "/usr/lib/python3.8/site-packages/sqlalchemy/engine/result.py", line 781, in _getter return self._non_result(None, err)

File "/usr/lib/python3.8/site-packages/sqlalchemy/engine/result.py", line 1236, in non_result util.raise(

File "/usr/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_ raise exception

sqlalchemy.exc.ResourceClosedError: This result object does not return rows. It has been closed automatically.

Is it possible to:

1. Continue logging HTTP GET requests to http.log
2. Send Falcon tracebacks and REST API errors to a separate log file

At the moment, both request logging and tracebacks appear in the same file.

Issue 5: Worker timeout

After the traceback above, I consistently see:

• [2026-08-03 12:21:29 +0000] [34] [CRITICAL] WORKER TIMEOUT (pid:52)
• [2026-08-03 12:21:30 +0000] [53] [INFO] Booting worker with pid: 53

This appears to indicate that the worker handling GET /3.1/lists/listname@example.com/config<mailto:/3.1/lists/listname@example.com/config> times out and is restarted.

Additional observations

error.log contains Mailman Core exceptions such as:

(52) deque: subscribe_from_restored

Traceback (most recent call last):

File "/usr/lib/python3.8/site-packages/mailman/app/workflow.py", line 69, in next return step()

File "/usr/lib/python3.8/site-packages/mailman/app/subscriptions.py", line 341, in _step_get_moderator_approval raise StopIteration

StopIteration

However, the Falcon/REST traceback shown above does not appear in error.log.

This suggests that:

• error.log receives Mailman Core exceptions.
• http.log receives REST API/Falcon exceptions.
• The two do not appear to be linked.

Questions

1. Is the mixed timestamp formatting expected in Mailman 3.3.4 Docker deployments?
2. Which component produces the starting oneloop / ending oneloop runner messages?
3. Can HTTP request logging and Falcon tracebacks be directed to separate log files?
4. Is ResourceClosedError when accessing GET /3.1/lists/listname@example.com/config<mailto:/3.1/lists/listname@example.com/config> a known Mailman 3.3.4 issue?
5. Is there a recommended logging configuration that preserves REST API access logging while reducing runner/debug noise?

Thanks in advance.

Best regards, Henrik