[Mailman-Users] Hello all - mailman down after power failure and hard shutdown

[Tanstaafl]

On 2013-06-08 1:58 PM, Mark Sapiro <mark at msapiro.net> wrote:
> Actually, private/local and private/retry refer to the sockets used for
> communication between the Postfix master and the various daemons. If you
> do 'netstat -l' you should see these and many others 'LISTENING', Do you?

Yep, they're all there. And local is working - at least sometimes (see 
below) :(

> I don't know why a reboot or even just a stop and start of Postfix
> doesn't fix this. If you stop and start Postfix, are there any messages
> in the mail logs beyond the "postfix/master[pppp]: daemon started ..."
> message?

Nothing more than the three warnings I already posted, two of which you 
see below, and the third being:

> 2013-06-08T13:10:19-04:00 myhost postfix/master[4076]: warning: master_wakeup_timer_event: service tlsmgr(private/tlsmgr): Resource temporarily unavailable

But, I have more details after some testing...

First, mailman is definitely working. I tested sending to one of my test 
lists with just two people on it, and it works fine:

> 2013-06-08T16:28:31-04:00 myhost postfix/qmgr[4078]: 88BA3831DC: from=<CMarcus at Media-Brokers.com>, size=743, nrcpt=1 (queue active)
> 2013-06-08T16:28:31-04:00 myhost postfix-587/smtpd[5878]: disconnect from client.atl.media-brokers.com[192.168.1.110]
> 2013-06-08T16:28:31-04:00 myhost postfix/local[5884]: 88BA3831DC: to=<test-list at smtp.media-brokers.com>, orig_to=<test-list at media-brokers.com>, relay=local, delay=0.31, delays=0.08/0/0/0.23, dsn=2.0.0, status=sent (delivered to command: /usr/lib64/mailman/mail/mailman post test-list)
> 2013-06-08T16:28:31-04:00 myhost postfix/qmgr[4078]: 88BA3831DC: removed
> 2013-06-08T16:28:32-04:00 myhost dovecot: imap(cmarcus at media-brokers.com): Connection closed in=1013 out=1725269
> 2013-06-08T16:28:32-04:00 myhost dovecot: imap-login: Login: user=<cmarcus at media-brokers.com>, method=PLAIN, rip=192.168.1.110, lport=993, mpid=5900, TLS, session=<T7IhZKreIgDAqAFu>
> 2013-06-08T16:28:33-04:00 myhost postfix-25/smtpd[5887]: connect from myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T16:28:33-04:00 myhost postfix-25/smtpd[5887]: 668EA831DC: client=myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T16:28:33-04:00 myhost postfix/cleanup[5883]: 668EA831DC: message-id=<51B393EF.2010908 at Media-Brokers.com>
> 2013-06-08T16:28:33-04:00 myhost postfix/qmgr[4078]: 668EA831DC: from=<test-list-bounces at media-brokers.com>, size=1269, nrcpt=1 (queue active)
> 2013-06-08T16:28:33-04:00 myhost postfix-25/smtpd[5887]: 77983189530: client=myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T16:28:33-04:00 myhost postfix/cleanup[5883]: 77983189530: message-id=<51B393EF.2010908 at Media-Brokers.com>
> 2013-06-08T16:28:33-04:00 myhost postfix/qmgr[4078]: 77983189530: from=<test-list-bounces at media-brokers.com>, size=1271, nrcpt=2 (queue active)
> 2013-06-08T16:28:33-04:00 myhost postfix-25/smtpd[5887]: disconnect from myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T16:28:33-04:00 myhost postfix/virtual[5889]: 77983189530: to=<recipient at media-brokers.com>, relay=virtual, delay=0.2, delays=0.05/0/0/0.15, dsn=2.0.0, status=sent (delivered to maildir)
> 2013-06-08T16:28:33-04:00 myhost postfix/pipe[5890]: 77983189530: to=<recipient#media-brokers.com at autoreply.media-brokers.com>, orig_to=<recipient at media-brokers.com>, relay=vacation, delay=0.4, delays=0.05/0/0/0.35, dsn=2.0.0, status=sent (delivered via vacation service)
> 2013-06-08T16:28:33-04:00 myhost postfix/qmgr[4078]: 77983189530: removed
> 2013-06-08T16:28:35-04:00 myhost postfix/smtp[5888]: 668EA831DC: to=<recipient at example.org>, relay=filtered.maildistiller.com[176.31.241.80]:25, delay=1.8, delays=0.07/0/0.62/1.1, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 0F38F157)
> 2013-06-08T16:28:35-04:00 myhost postfix/qmgr[4078]: 668EA831DC: removed

I tested with another list that has 6 people on it, two of whom have 
their vacation message enabled (I use postfixadmin vacation), and while 
all 6 recipients got the message, there were two messages that got stuck 
in the queue that are related to the vacation message:

> 2013-06-08T16:36:50-04:00 myhost postfix/qmgr[4078]: 4F86719D832: from=<CMarcus at Media-Brokers.com>, size=935, nrcpt=1 (queue active)
> 2013-06-08T16:36:50-04:00 myhost postfix-587/smtpd[5968]: disconnect from client.atl.media-brokers.com[192.168.1.110]
> 2013-06-08T16:36:50-04:00 myhost postfix/local[5970]: 4F86719D832: to=<test-list2 at smtp.media-brokers.com>, orig_to=<test-list2 at media-brokers.com>, relay=local, delay=0.28, delays=0.09/0.01/0/0.18, dsn=2.0.0, status=sent (delivered to command: /usr/lib64/mailman/mail/mailman post test-list2)
> 2013-06-08T16:36:50-04:00 myhost postfix/qmgr[4078]: 4F86719D832: removed
> 2013-06-08T16:36:52-04:00 myhost postfix-25/smtpd[5973]: connect from myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T16:36:52-04:00 myhost postfix-25/smtpd[5973]: 22FAC19D832: client=myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T16:36:52-04:00 myhost postfix/cleanup[5969]: 22FAC19D832: message-id=<51B395E2.7070107 at Media-Brokers.com>
> 2013-06-08T16:36:52-04:00 myhost postfix/qmgr[4078]: 22FAC19D832: from=<test-list2-bounces at media-brokers.com>, size=1442, nrcpt=9 (queue active)
> 2013-06-08T16:36:52-04:00 myhost postfix-25/smtpd[5973]: disconnect from myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T16:36:52-04:00 myhost postfix/qmgr[4078]: warning: connect to transport private/vacation: Resource temporarily unavailable
> 2013-06-08T16:36:52-04:00 myhost postfix/qmgr[4078]: warning: connect to transport private/retry: Resource temporarily unavailable
> 2013-06-08T16:36:52-04:00 myhost postfix/qmgr[4078]: 22FAC19D832: to=<validuser1#media-brokers.com at autoreply.media-brokers.com>, orig_to=<validuser at media-brokers.com>, relay=none, delay=0.15, delays=0.07/0.08/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)
> 2013-06-08T16:36:52-04:00 myhost postfix/qmgr[4078]: 22FAC19D832: to=<validuser2#media-brokers.com at autoreply.media-brokers.com>, orig_to=<validuser2 at media-brokers.com>, relay=none, delay=0.21, delays=0.07/0.14/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)
> 2013-06-08T16:36:52-04:00 myhost postfix/virtual[5974]: 22FAC19D832: to=<validuser3 at media-brokers.com>, relay=virtual, delay=0.28, delays=0.07/0.14/0/0.07, dsn=2.0.0, status=sent (delivered to maildir)
> 2013-06-08T16:36:52-04:00 myhost postfix/virtual[5974]: 22FAC19D832: to=<validuser4 at media-brokers.com>, relay=virtual, delay=0.37, delays=0.07/0.14/0/0.16, dsn=2.0.0, status=sent (delivered to maildir)
> 2013-06-08T16:36:52-04:00 myhost postfix/virtual[5974]: 22FAC19D832: to=<validuser5 at media-brokers.com>, relay=virtual, delay=0.47, delays=0.07/0.14/0/0.25, dsn=2.0.0, status=sent (delivered to maildir)
> 2013-06-08T16:36:52-04:00 myhost postfix/virtual[5974]: 22FAC19D832: to=<validuser1 at media-brokers.com>, relay=virtual, delay=0.56, delays=0.07/0.14/0/0.35, dsn=2.0.0, status=sent (delivered to maildir)
> 2013-06-08T16:36:52-04:00 myhost postfix/virtual[5974]: 22FAC19D832: to=<validuser6 at media-brokers.com>, relay=virtual, delay=0.65, delays=0.07/0.14/0/0.43, dsn=2.0.0, status=sent (delivered to maildir)
> 2013-06-08T16:36:52-04:00 myhost postfix/virtual[5974]: 22FAC19D832: to=<validuser7 at media-brokers.com>, relay=virtual, delay=0.72, delays=0.07/0.14/0/0.51, dsn=2.0.0, status=sent (delivered to maildir)
> 2013-06-08T16:36:53-04:00 myhost postfix/virtual[5974]: 22FAC19D832: to=<validuser2 at media-brokers.com>, relay=virtual, delay=0.88, delays=0.07/0.14/0/0.66, dsn=2.0.0, status=sent (delivered to maildir)

As you can see, only the two vacation messages are deferred with 
transport unavailable.

It also appears that the problem manifests with NESTED lists:

> 2013-06-08T17:07:43-04:00 myhost postfix/qmgr[4078]: 8485738737A: from=<CMarcus at Media-Brokers.com>, size=3474, nrcpt=1 (queue active)
> 2013-06-08T17:07:43-04:00 myhost postfix-587/smtpd[6187]: disconnect from client.atl.media-brokers.com[192.168.1.110]
> 2013-06-08T17:07:43-04:00 myhost postfix/local[6190]: 8485738737A: to=<lists-all at smtp.media-brokers.com>, orig_to=<lists-all at Media-Brokers.com>, relay=local, delay=0.3, delays=0.08/0/0/0.22, dsn=2.0.0, status=sent (delivered to command: /usr/lib64/mailman/mail/mailman post lists-all)
> 2013-06-08T17:07:43-04:00 myhost postfix/qmgr[4078]: 8485738737A: removed
> 2013-06-08T17:07:44-04:00 myhost postfix-25/smtpd[6206]: connect from myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T17:07:44-04:00 myhost postfix-25/smtpd[6206]: D682B38737A: client=myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T17:07:44-04:00 myhost postfix/cleanup[6182]: D682B38737A: message-id=<51B39D1F.3050404 at Media-Brokers.com>
> 2013-06-08T17:07:44-04:00 myhost postfix/qmgr[4078]: D682B38737A: from=<lists-all-bounces at media-brokers.com>, size=3933, nrcpt=6 (queue active)
> 2013-06-08T17:07:44-04:00 myhost postfix-25/smtpd[6206]: disconnect from myhost.media-brokers.com[127.0.0.1]
> 2013-06-08T17:07:44-04:00 myhost postfix/qmgr[4078]: warning: connect to transport private/local: Resource temporarily unavailable
> 2013-06-08T17:07:44-04:00 myhost postfix/qmgr[4078]: warning: connect to transport private/retry: Resource temporarily unavailable
> 2013-06-08T17:07:45-04:00 myhost postfix/qmgr[4078]: D682B38737A: to=<list-1 at smtp.media-brokers.com>, orig_to=<list-1 at media-brokers.com>, relay=none, delay=0.17, delays=0.1/0.08/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)
> 2013-06-08T17:07:45-04:00 myhost postfix/qmgr[4078]: D682B38737A: to=<list-2 at smtp.media-brokers.com>, orig_to=<list-2 at media-brokers.com>, relay=none, delay=0.22, delays=0.1/0.13/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)
> 2013-06-08T17:07:45-04:00 myhost postfix/qmgr[4078]: D682B38737A: to=<list-3 at smtp.media-brokers.com>, orig_to=<list-3 at media-brokers.com>, relay=none, delay=0.3, delays=0.1/0.2/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)
> 2013-06-08T17:07:45-04:00 myhost postfix/qmgr[4078]: D682B38737A: to=<list-4 at smtp.media-brokers.com>, orig_to=<list-4 at media-brokers.com>, relay=none, delay=0.36, delays=0.1/0.26/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)
> 2013-06-08T17:07:45-04:00 myhost postfix/qmgr[4078]: D682B38737A: to=<list-5 at smtp.media-brokers.com>, orig_to=<list-5 at media-brokers.com>, relay=none, delay=0.41, delays=0.1/0.32/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)
> 2013-06-08T17:07:45-04:00 myhost postfix/qmgr[4078]: D682B38737A: to=<list-6 at smtp.media-brokers.com>, orig_to=<list-6 at media-brokers.com>, relay=none, delay=0.47, delays=0.1/0.37/0/0, dsn=4.3.0, status=deferred (mail transport unavailable)

I imagine that the two problems are being caused by the same problem, 
whatever it is...

It also seems to be something to do with how many recipients are 
involved. One or two appear to be ok, but more than that and it gets iffy...

Appreciate any more thoughts on this weirdness, because I'm stumped....