[Mailman-Users] Performance issues with 12K subscribers and 14K subscribers and personalized footers.

[Mark Sapiro]

On 09/27/2013 11:17 AM, Bryan Wright wrote:
> 
> I've configured mailman for 48 outgoing qrunners, and have tried as many as 72 qrunners, with no noticeable difference, it's like it's using only the 1st outgoing qrunner to process the message and the rest stay there idle.  And then it uses that one qrunner process to create each separate message.  So 12k individual messages processed by one qrunner thread each time.  Is there some way to speed this up and/or get it to use multiple outgoing qrunners simultaneously for the same post, since with personalization it has to create individual copies of each message?


In your case this will not help at all. A single OutgoingRunner will be
just as fast (or slow) because all the messages are for one or at most
two lists, and list lock contention will thwart any attempt at
parallelism. Furthermore, parallism only works for multiple messages.
Delivery of a single post is always handled by a single OutgoingRunner.


> The other odd thing is it doesn't log all 12K messages in the smtp log from mailman, but it logs more than 1.  I would have thought it would either log only 1 message, or all 12K messages.
> 
> Here is the SMTP log from mailman:
> 
> Sep 26 14:13:17 2013 (12407) <mailman.0.1380222786.19117.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.368 seconds
> Sep 26 15:11:57 2013 (12439) <mailman.0.1380226308.21360.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 8.107 seconds
> Sep 26 15:42:19 2013 (12381) <mailman.0.1380228138.22559.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 0.086 seconds
> Sep 26 16:56:31 2013 (12458) <mailman.0.1380232579.25376.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 11.179 seconds
> Sep 26 17:21:12 2013 (12469) <mailman.0.1380234070.26307.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 1.012 seconds
> Sep 26 19:10:10 2013 (12429) <mailman.0.1380240598.30473.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.988 seconds
> Sep 26 20:23:43 2013 (12449) <mailman.0.1380245014.711.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 6.958 seconds
> Sep 27 00:47:25 2013 (12380) <mailman.0.1380260837.10913.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 6.096 seconds
> Sep 27 01:17:13 2013 (12448) <mailman.0.1380262626.12154.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 6.166 seconds
> Sep 27 02:11:27 2013 (12442) <mailman.0.1380265881.14347.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 5.095 seconds
> Sep 27 02:30:36 2013 (12399) <mailman.0.1380267029.15040.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 6.013 seconds
> Sep 27 02:40:08 2013 (12472) <mailman.0.1380267601.15415.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 5.356 seconds
> Sep 27 05:07:31 2013 (12380) <mailman.0.1380276450.12376.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 0.083 seconds
> Sep 27 05:08:20 2013 (12422) <mailman.1.1380276500.12376.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 0.077 seconds
> Sep 27 05:08:23 2013 (12474) <mailman.2.1380276502.12376.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 0.073 seconds
> Sep 27 05:31:24 2013 (12438) <mailman.0.1380277874.22335.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.251 seconds
> Sep 27 06:56:34 2013 (12469) <mailman.0.1380282987.25737.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 5.967 seconds
> Sep 27 06:56:50 2013 (12396) <mailman.0.1380283004.25755.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 5.153 seconds
> Sep 27 07:02:33 2013 (12452) <mailman.0.1380283341.25998.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.248 seconds
> Sep 27 07:59:36 2013 (12406) <mailman.0.1380286763.28405.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 11.085 seconds
> Sep 27 08:05:46 2013 (12417) <mailman.0.1380287135.28700.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.141 seconds
> Sep 27 08:10:38 2013 (12449) <mailman.0.1380287426.28903.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.232 seconds
> Sep 27 08:11:40 2013 (12435) <mailman.0.1380287489.28951.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.093 seconds
> Sep 27 08:28:37 2013 (12473) <mailman.0.1380288511.29608.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 5.124 seconds
> Sep 27 08:35:08 2013 (12409) <mailman.0.1380288897.29894.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.346 seconds
> Sep 27 09:51:39 2013 (12428) <mailman.0.1380293492.733.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 5.045 seconds
> Sep 27 10:34:31 2013 (12393) <mailman.0.1380296069.2689.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 0.049 seconds
> Sep 27 11:39:33 2013 (12396) <mailman.0.1380299956.5227.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 15.162 seconds
> Sep 27 11:40:15 2013 (12389) <mailman.0.1380300003.5287.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.073 seconds
> Sep 27 11:53:41 2013 (12438) <mailman.0.1380300815.5850.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 5.098 seconds
> Sep 27 13:00:33 2013 (12430) <mailman.0.1380304821.8504.newsletter at rigaku.com> smtp to newsletter for 1 recips, completed in 10.125 seconds


These messages are all Mailman generated notices of some kind. None of
them is delivery of the actual post to the 12 or 14 K subscribers.
Further, these do not indicate a backlogged qrunner since these messages
are many minutes apart and processing times, although very long for a
single recipient, are only a few seconds.

Most of these entries look like a single notice, although there may have
been others that are in the slice being processed for the big delivery,
but these

Sep 27 05:07:31 2013 (12380)
<mailman.0.1380276450.12376.newsletter at rigaku.com> smtp to newsletter
for 1 recips, completed in 0.083 seconds
Sep 27 05:08:20 2013 (12422)
<mailman.1.1380276500.12376.newsletter at rigaku.com> smtp to newsletter
for 1 recips, completed in 0.077 seconds
Sep 27 05:08:23 2013 (12474)
<mailman.2.1380276502.12376.newsletter at rigaku.com> smtp to newsletter
for 1 recips, completed in 0.073 seconds

appear to be
 (.0.) a notice to a user
 (.1.) a related notice to newsletter-owner at rigaku.com
 (.2.) the resend of (.1.) to the actual owner address.

The actual delivery to the subscribers will be a log entry like

Mmm dd hh:mm:ss (qrunner PID) <message ID of the incoming post> smtp to
newsletter for nnnnn recips, completed in ttttt.ttt seconds

(where nnnnn is the size of the list and ttttt.ttt is the total time)
written after delivery is complete.

I suspect that that what is happening here is some deliveries are
bouncing and some of those bounces are disabling delivery and the
entries you show above are bounce processing notices and they take as
long as they do because of sendmail contention with the actual delivery
of the post. Also, you only see them while delivery of the post is
proceeding because of multiple qrunners, but I'm not sure why locking
doesn't stop even that.


> Thanks in advance for any advice/help you can give.


See the FAQs at <http://wiki.list.org/x/doA9> and
<http://wiki.list.org/x/q4A9>.

-- 
Mark Sapiro <mark at msapiro.net>        The highway is for gamblers,
San Francisco Bay Area, California    better use your sense - B. Dylan