RE: "opendkim dead but subsys locked" yet there are opendkim processes

From: Tracy Wise <tracywise_at_hotmail.com>
Date: Fri, 18 Jan 2013 03:27:27 +0000

Please pardon me, I had forgotten to re-enable Syslog in opendkim.conf.  I re-enabled that, and now I got this very useful info logged from opendkim:

Jan 17 22:24:26 webcamchurch opendkim[5638]: can't load key from /etc/opendkim/keys/webcamchurch.com/webcamchurch                                                                                    : Permission denied
Jan 17 22:24:26 webcamchurch opendkim[5638]: D261B20673: error loading key 'webcamchurch._domainkey.webcamchurch.                                                                                    com'

So now I'm on the right track, at least I now have some idea where the problem lies.



________________________________
> From: tracywise_at_hotmail.com
> To: opendkim-users_at_lists.opendkim.org
> Subject: RE: "opendkim dead but subsys locked" yet there are opendkim
> processes
> Date: Fri, 18 Jan 2013 02:17:19 +0000
>
> Murray:
>
> Thanks for your help. In response to your question, I get all of this
> output in the maillog for each attempt to send one test mail from a PHP
> script:
>
> Jan 17 21:12:05 webcamchurch postfix/pickup[30558]: 071C120697: uid=502
> from=<help_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5149]: 071C120697:
> message-id=<20130118021205.071C120697_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5149]: 071C120697:
> milter-reject: END-OF-MESSAGE from localhost[127.0.0.1]: 4.7.1 Service
> unavailable - try again later; from=<help_at_webcamchurch.com>
> to=<penpals_at_christianweb.com>
> Jan 17 21:12:05 webcamchurch postfix/pickup[30558]: 0777120697: uid=502
> from=<help_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5184]: 0777120697:
> message-id=<20130118021205.0777120697_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5184]: 0777120697:
> milter-reject: END-OF-MESSAGE from localhost[127.0.0.1]: 4.7.1 Service
> unavailable - try again later; from=<help_at_webcamchurch.com>
> to=<penpals_at_christianweb.com>
> Jan 17 21:12:05 webcamchurch postfix/pickup[30558]: 07C3B20697: uid=502
> from=<help_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5149]: 07C3B20697:
> message-id=<20130118021205.07C3B20697_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5149]: 07C3B20697:
> milter-reject: END-OF-MESSAGE from localhost[127.0.0.1]: 4.7.1 Service
> unavailable - try again later; from=<help_at_webcamchurch.com>
> to=<penpals_at_christianweb.com>
> Jan 17 21:12:05 webcamchurch postfix/pickup[30558]: 0801520697: uid=502
> from=<help_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5184]: 0801520697:
> message-id=<20130118021205.0801520697_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5184]: 0801520697:
> milter-reject: END-OF-MESSAGE from localhost[127.0.0.1]: 4.7.1 Service
> unavailable - try again later; from=<help_at_webcamchurch.com>
> to=<penpals_at_christianweb.com>
> Jan 17 21:12:05 webcamchurch postfix/pickup[30558]: 083C720697: uid=502
> from=<help_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5149]: 083C720697:
> message-id=<20130118021205.083C720697_at_webcamchurch.com>
> Jan 17 21:12:05 webcamchurch postfix/cleanup[5149]: 083C720697:
> milter-reject: END-OF-MESSAGE from localhost[127.0.0.1]: 4.7.1 Service
> unavailable - try again later; from=<help_at_webcamchurch.com>
> to=<penpals_at_christianweb.com>
>
> By the way, I should mention that I recently changed one line of
> opendkim.conf from:
>
> Socket inet:8891_at_localhost
>
> to:
>
> Socket inet:8891_at_127.0.0.1
>
> I did that because of a tip from a post I saw somewhere. Should I
> change it back, or is it fine like that?
>
> ----------------------------------------
> > Date: Thu, 17 Jan 2013 12:52:34 -0800
> > From: msk_at_blackops.org
> > To: tracywise_at_hotmail.com
> > CC: opendkim-users_at_lists.opendkim.org
> > Subject: RE: "opendkim dead but subsys locked" yet there are opendkim
> processes
> >
> > On Thu, 17 Jan 2013, Tracy Wise wrote:
> > > So, from my very limited knowledge, it appears that opendkim did indeed
> > > bind to that port, not another process. Or am I wrong on that?
> >
> > In that case it looks like there's an opendkim up and providing service,
> > but there's also another one trying (and failing) to start up on the same
> > port, and that's caught in a restart loop. Since you tried a reboot, it
> > looks like your startup environment is starting opendkim twice; the first
> > one works, the second one enters a restart loop.
> >
> > Since AutoRestartRate is set to 10/1h, then I'm left to conclude that the
> > second opendkim instance will give up after ten quick retries (or at
> > least, it should). The parent will then terminate. That you have 30Gb of
> > logs in one case suggests that there's something watching even the parent
> > and restarting it, which is where the loop really comes from. This could
> > be Plesk, but that's merely a guess since I've never used it.
> >
> > Focusing for a moment on the opendkim that is up and listening on 8891,
> > your postfix instance should be talking to it and getting mail signed
> > outbound. Is either postfix or opendkim logging anything that might
> > explain why it's not allowing mail to depart?
> >
> > -MSK
Received on Fri Jan 18 2013 - 03:27:40 PST