Messages not going to held queue
Hi all,
Not sure why, but messages set to be held for moderation are appearing to be discarded. I've tried creating a new test list, adjusting settings at the user and list level, but when a user sends a message that should be held for moderation, nothing happens. smtp.log shows the message is going through but it doesn't get to the moderation queue.
Mail Person writes:
Not sure why, but messages set to be held for moderation
There are quite a few settings that can result in moderation holds. Which are you talking about, and exactly what is the setting?
appearing to be discarded.
Have you checked the other logs? A discard should show up in the 'vette' log. If there's no notice there, the message should be stuck in some queue, my first guess is shunt, but it could be anywhere.
smtp.log shows the message is going through but it doesn't get to the moderation queue.
How do you know? Do you mean moderators don't get email that the message is held, or have you checked in Postorius and it tells you no messages are available for moderation?
I believe that if the message is waiting for moderation it should be in the 'pipeline' queue.
Steve
I have it set so that members automatically go to the moderation queue from the Postorius settings. To make sure that wasn't the issue, I also added a test subscriber account to the list and set them manually to have their messages held for moderation. I then set them to "accept immediately" to make sure Postorius settings were taking effect. When "accept immediately" was set, the messages were sent through. When they were set to be held for moderation, the user did not get a moderation email, myself as the moderator did not get a notification, and Postorius did not show them in the held messages queue.
As far as logs, in var/log/mailman3 I do not see any logs other than mailman.log, plugins.log and smtp.log. In the SMTP log I can see that the message is getting to mailman:
Sep 07 20:10:08 2022 (2837) ('127.0.0.1', 45958) Data: b'MAIL FROM:<test email>' Sep 07 20:10:08 2022 (2837) ('127.0.0.1', 45958) sender: test email Sep 07 20:10:08 2022 (2837) ('127.0.0.1', 45958) Data: b'RCPT TO:test@domain'
however no action is taken after that. In the cases where the message is sent I there are two actions showing the message going out:
Sep 07 20:10:09 2022 (2839) stuff@mail.gmail.com smtp to test@domain for 2 recips, completed in 0.14289569854736328 seconds Sep 07 20:10:09 2022 (2839) stuff@mail.gmail.com post to test@domain from testemail, 2969 bytes
This leads me to believe the message is being discarded or for some reason not getting to the moderation queue.
Mail Person writes:
I have it set
I guess by "it" you mean the user's moderation status, but there are *many* variables that affect whether mail is delivered or not. These include emergency moderation, spam filtering, and HTML handling (and there are probably others I don't remember off the top of my head), as well as individual variables such as not_metoo and the moderation status. All I can rule out is emergency_moderation, because that would prevent your test mail from being delivered when the test user is set to allow.
the user did not get a moderation email, myself as the moderator did not get a notification, and Postorius did not show them in the held messages queue.
When you set the test user to accept, did you set it to "accept" or to "default processing"? Setting it to "accept" bypasses almost all of the acceptance checks. Usually "default processing" is what you want.
As far as logs, in var/log/mailman3 I do not see any logs other than mailman.log, plugins.log and smtp.log. In the SMTP log I can see that the message is getting to mailman:
Does mailman.log show any errors?
This leads me to believe the message is being discarded or for some reason not getting to the moderation queue.
Sure, but Mailman doesn't do that for no reason. The only thing I can think of offhand that might happen in a mostly default configuration is that you're using an MUA that creates a multipart message where the plain part is empty and the actual message is HTML (yes, I've seen that in the wild). In some configurations that would cause the HTML part to be deleted, then the message could be recognized as empty and discarded. I haven't analyzed the code thoroughly but I don't recall a log message on that execution path so it might fit your case.
Yes, I am talking about "Default action to take when a member posts to the list" and also at the user level "Moderation" (List default, hold, reject, etc.). The discard and hold settings work both when applied as default and at the user level, but hold for moderation does not.
As far as logs I just noticed two things, there is a long Python Error that ends with a shunt:
Sep 08 14:51:38 2022 (2836) Uncaught runner exception: module 'time' has no attribute 'clock' Sep 08 14:51:38 2022 (2836) Traceback (most recent call last): File "/usr/lib/python3/dist-packages/mailman/core/runner.py", line 173, in _one_iteration self._process_one_file(msg, msgdata) File "/usr/lib/python3/dist-packages/mailman/core/runner.py", line 266, in _process_one_file keepqueued = self._dispose(mlist, msg, msgdata) File "/usr/lib/python3/dist-packages/mailman/runners/incoming.py", line 79, in _dispose process(mlist, msg, msgdata, start_chain) File "/usr/lib/python3/dist-packages/mailman/core/chains.py", line 79, in process link.function(mlist, msg, msgdata) File "/usr/lib/python3/dist-packages/mailman/chains/hold.py", line 147, in _process request_id = hold_message(mlist, msg, msgdata, SEMISPACE.join(reasons)) File "/usr/lib/python3/dist-packages/mailman/app/moderator.py", line 88, in hold_message request_id = requestsdb.hold_request( File "/usr/lib/python3/dist-packages/mailman/database/transaction.py", line 85, in wrapper return function(args[0], config.db.store, *args[1:], **kws) File "/usr/lib/python3/dist-packages/mailman/model/requests.py", line 100, in hold_request token = getUtility(IPendings).add(pendable, timedelta(days=5000)) File "/usr/lib/python3/dist-packages/mailman/database/transaction.py", line 85, in wrapper return function(args[0], config.db.store, *args[1:], **kws) File "/usr/lib/python3/dist-packages/mailman/model/pending.py", line 91, in add token = token_factory.new() File "/usr/lib/python3/dist-packages/mailman/utilities/uid.py", line 79, in new return self._next_unpredictable_id() File "/usr/lib/python3/dist-packages/mailman/utilities/uid.py", line 155, in _next_unpredictable_id x = random.random() + right_now % 1.0 + time.clock() % 1.0 AttributeError: module 'time' has no attribute 'clock' Sep 08 14:51:38 2022 (2836) SHUNTING: 1662648698.613485+f3b28cbd19188e52f59e2ed5fa4237be035cc2be
Mail Person writes:
x = random.random() + right_now % 1.0 + time.clock() % 1.0
You appear to be using a version of Mailman distributed before December 26, 2015, which we cannot support. It is not compatible with any Python more recent than Python 3.7 (end of life 27 June 2023). I recommend you upgrade to more recent versions of the Mailman suite, which are available on PyPI, or perhaps through your OS distribution.
Steve
Mail Person writes:
I'm currently running 3.3.5
The code referenced in your traceback was removed in December 2015. It's simply not there, the whole function moved to a different file and the reference to time.clock became time.time in more recent versions. There is only one reference to clock() in the whole codebase, in the comment explaining this change. I've verified it's not in the 3.3.5 package available on PyPI.
So whatever is handling your list, it is not the code tagged 3.3.5 in our repository. It seems possible that your system is also running some experiment with Mailman 3 from ages ago, and that's what's handling your list traffic. If so, find it, uninstall it, and check the MTA configuration to make sure it will find the installed 3.3.5.
It's also possible you got it somewhere such as a Linux distro, and they have a patch in that file that prevented upgrading that code to 3.3.5. If so, you should report the bug to them.
In the meantime you may want to uninstall theirs and install ours from PyPI. If that causes trouble because of MTA or webserver setup left over from the distro install, I'll be happy to work with you on that.
Or you can install an old Python, which might make it work OK. (3.7 is recommended for this purpose since it still receives security patches, but you have to install them yourself. 3.6 is already completely out of support). However, we still can't support this version of Mailman because it's not our code. If you choose this route you'll have to get support from wherever you got this version of Mailman.
Steve
On 9/8/22 10:08, Mail Person wrote:
I'm currently running 3.3.5
But your traceback says:
File "/usr/lib/python3/dist-packages/mailman/utilities/uid.py", line
155, in _next_unpredictable_id
x = random.random() + right_now % 1.0 + time.clock() % 1.0
AttributeError: module 'time' has no attribute 'clock'
and that line was changed to
x = random.random() + right_now % 1.0 + time.process_time() % 1.0
by https://gitlab.com/mailman/mailman/-/merge_requests/552 in Mailman
3.3.0 so the traceback you report at
https://lists.mailman3.org/archives/list/mailman-users@mailman3.org/message/EC2DTCULSVCRR2ZPWVZXZU67KX3MZ46P/
was produced by Mailman < 3.3.0.
-- Mark Sapiro mark@msapiro.net The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
participants (3)
-
Mail Person -
Mark Sapiro -
Stephen J. Turnbull