OpenDKIM but no log of postfix milter running or trying to run

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
9 messages Options
Reply | Threaded
Open this post in threaded view
|

OpenDKIM but no log of postfix milter running or trying to run

Jeff Abrahamson

I've set up OpenDKIM.  I've noted the config below, but the basic issue is that my mails aren't being DKIM signed and my logs, while showing no mail-related errors, also don't show any evidence of milters running or trying to run.  So I'm suspecting postfix config error rather than opendkim.  So far all doc reading and googling is leading me nowhere immediately helpful.

I'm trying to figure out what's wrong or at least how to debug it further.  (This is all on ubuntu 16.04.6 LTS.  I sadly need to get this working before I can spend the time to transition us to a 20.04 host.)  Postfix is v 3.1.0, opendkim is 2.10.3.

This is the relevant config I've added to my /etc/postfix/main.cf:

smtpd_milters           = inet:127.0.0.1:8891
non_smtpd_milters       = $smtpd_milters
milter_default_action   = accept
milter_protocol         = 6
# Appears default doesn't include {auth_type}.
# Cf. http://www.opendkim.org/opendkim.8.html
milter_mail_macros="i {mail_addr} {client_addr} {client_name} {auth_type} {auth_authen}"

The OpenDKIM config is this:

Canonicalization        relaxed/relaxed
ExternalIgnoreList      refile:/etc/opendkim/TrustedHosts
InternalHosts           refile:/etc/opendkim/TrustedHosts
KeyTable                refile:/etc/opendkim/KeyTable
LogWhy                  Yes
# MilterDebug        0
MilterDebug        1
MinimumKeyBits          1024
Mode                    sv
PidFile                 /var/run/opendkim/opendkim.pid
SigningTable            refile:/etc/opendkim/SigningTable
# Must agree with value in /etc/default/opendkim.
Socket                  inet:8891@localhost
Syslog                  Yes
SyslogSuccess           Yes
TemporaryDirectory      /var/tmp
UMask                   022
UserID                  opendkim:opendkim
OversignHeaders         From
SignatureAlgorithm      rsa-sha256
AutoRestart             Yes

KeyTable is

nantes-1.p27.eu   p27.eu:mail:/etc/opendkim/p27.eu.key

SigningTable is

*@p27.eu                 nantes-1.p27.eu
*@transport-nantes.com   nantes-1.p27.eu

and TrustedHosts (which may not be needed) is

127.0.0.1

Any suggestions?

-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/
Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

ilyak
Set "milter_default_action" to "reject", reload postfix, and try to send mail. 
You should probably get some errors in maillog.
Check your syslog config, to make sure opendkim logs are also written.

Check your dkim is running (telnet 127.0.0.1 8891).

Btw, I have not set "milter_mail_macros" explicitly. 
The default on my system is "milter_mail_macros = i {auth_type} {auth_authen} {auth_author} {mail_addr} {mail_host} {mail_mailer}" and it works.


On Wed, Oct 14, 2020 at 1:27 PM Jeff Abrahamson <[hidden email]> wrote:

I've set up OpenDKIM.  I've noted the config below, but the basic issue is that my mails aren't being DKIM signed and my logs, while showing no mail-related errors, also don't show any evidence of milters running or trying to run.  So I'm suspecting postfix config error rather than opendkim.  So far all doc reading and googling is leading me nowhere immediately helpful.

I'm trying to figure out what's wrong or at least how to debug it further.  (This is all on ubuntu 16.04.6 LTS.  I sadly need to get this working before I can spend the time to transition us to a 20.04 host.)  Postfix is v 3.1.0, opendkim is 2.10.3.

This is the relevant config I've added to my /etc/postfix/main.cf:

smtpd_milters           = inet:127.0.0.1:8891
non_smtpd_milters       = $smtpd_milters
milter_default_action   = accept
milter_protocol         = 6
# Appears default doesn't include {auth_type}.
# Cf. http://www.opendkim.org/opendkim.8.html
milter_mail_macros="i {mail_addr} {client_addr} {client_name} {auth_type} {auth_authen}"

The OpenDKIM config is this:

Canonicalization        relaxed/relaxed
ExternalIgnoreList      refile:/etc/opendkim/TrustedHosts
InternalHosts           refile:/etc/opendkim/TrustedHosts
KeyTable                refile:/etc/opendkim/KeyTable
LogWhy                  Yes
# MilterDebug        0
MilterDebug        1
MinimumKeyBits          1024
Mode                    sv
PidFile                 /var/run/opendkim/opendkim.pid
SigningTable            refile:/etc/opendkim/SigningTable
# Must agree with value in /etc/default/opendkim.
Socket                  inet:8891@localhost
Syslog                  Yes
SyslogSuccess           Yes
TemporaryDirectory      /var/tmp
UMask                   022
UserID                  opendkim:opendkim
OversignHeaders         From
SignatureAlgorithm      rsa-sha256
AutoRestart             Yes

KeyTable is

nantes-1.p27.eu   p27.eu:mail:/etc/opendkim/p27.eu.key

SigningTable is

*@p27.eu                 nantes-1.p27.eu
*@transport-nantes.com   nantes-1.p27.eu

and TrustedHosts (which may not be needed) is

127.0.0.1

Any suggestions?

-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/
Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

Jeff Abrahamson

Thanks.  The suggestion to set milter_default_action to reject is good.  (I also tried unsetting milter_mail_macros.)  Strangely, it doesn't cause a rejection:

Oct 14 15:42:53 nantes-1 postfix/smtps/smtpd[5954]: connect from w.z.y.x.rev.sfr.net[x.y.z.w]
Oct 14 15:42:53 nantes-1 postfix/smtps/smtpd[5954]: Anonymous TLS connection established from 10.244.88.92.rev.sfr.net[92.88.244.10]: TLSv1 with cipher ECDHE-RSA-AES128-SHA (128/128 bits)
Oct 14 15:42:54 nantes-1 postfix/smtps/smtpd[5954]: 05102FDD7F: client=w.z.y.x.rev.sfr.net[x.y.z.w], sasl_method=PLAIN, sasl_username=jeff
Oct 14 15:42:54 nantes-1 postfix/cleanup[5959]: 05102FDD7F: message-id=[hidden email]
Oct 14 15:42:54 nantes-1 postfix/qmgr[5926]: 05102FDD7F: from=[hidden email], size=2588, nrcpt=1 (queue active)
Oct 14 15:42:54 nantes-1 postfix/smtps/smtpd[5954]: disconnect from w.z.y.x.rev.sfr.net[x.y.z.w] ehlo=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=6
Oct 14 15:42:54 nantes-1 dovecot: imap(jeff): Connection closed (IDLE running for 0.001 + waiting input for 246.717 secs, 2 B in + 10+10 B out, state=wait-input) in=2669 out=365094
Oct 14 15:42:54 nantes-1 postfix/smtp[5960]: 05102FDD7F: to=[hidden email], relay=ASPMX.L.GOOGLE.com[108.177.119.26]:25, delay=0.5, delays=0.13/0.01/0.1/0.27, dsn=2.0.0, status=sent (250 2.0.0 OK  1602682974 y9si2260509ejg.460 - gsmtp)
Oct 14 15:42:54 nantes-1 postfix/qmgr[5926]: 05102FDD7F: removed

The config file is active, however.  If I simply introduce a syntax error, postfix won't restart.  So somehow I seem to have disabled milter support.  I didn't know that was possible.

Jeff


On 14/10/2020 14:08, IL Ka wrote:
Set "milter_default_action" to "reject", reload postfix, and try to send mail. 
You should probably get some errors in maillog.
Check your syslog config, to make sure opendkim logs are also written.

Check your dkim is running (telnet 127.0.0.1 8891).

Btw, I have not set "milter_mail_macros" explicitly. 
The default on my system is "milter_mail_macros = i {auth_type} {auth_authen} {auth_author} {mail_addr} {mail_host} {mail_mailer}" and it works.


On Wed, Oct 14, 2020 at 1:27 PM Jeff Abrahamson <[hidden email]> wrote:

I've set up OpenDKIM.  I've noted the config below, but the basic issue is that my mails aren't being DKIM signed and my logs, while showing no mail-related errors, also don't show any evidence of milters running or trying to run.  So I'm suspecting postfix config error rather than opendkim.  So far all doc reading and googling is leading me nowhere immediately helpful.

I'm trying to figure out what's wrong or at least how to debug it further.  (This is all on ubuntu 16.04.6 LTS.  I sadly need to get this working before I can spend the time to transition us to a 20.04 host.)  Postfix is v 3.1.0, opendkim is 2.10.3.

This is the relevant config I've added to my /etc/postfix/main.cf:

smtpd_milters           = inet:127.0.0.1:8891
non_smtpd_milters       = $smtpd_milters
milter_default_action   = accept
milter_protocol         = 6
# Appears default doesn't include {auth_type}.
# Cf. http://www.opendkim.org/opendkim.8.html
milter_mail_macros="i {mail_addr} {client_addr} {client_name} {auth_type} {auth_authen}"

The OpenDKIM config is this:

Canonicalization        relaxed/relaxed
ExternalIgnoreList      refile:/etc/opendkim/TrustedHosts
InternalHosts           refile:/etc/opendkim/TrustedHosts
KeyTable                refile:/etc/opendkim/KeyTable
LogWhy                  Yes
# MilterDebug        0
MilterDebug        1
MinimumKeyBits          1024
Mode                    sv
PidFile                 /var/run/opendkim/opendkim.pid
SigningTable            refile:/etc/opendkim/SigningTable
# Must agree with value in /etc/default/opendkim.
Socket                  inet:8891@localhost
Syslog                  Yes
SyslogSuccess           Yes
TemporaryDirectory      /var/tmp
UMask                   022
UserID                  opendkim:opendkim
OversignHeaders         From
SignatureAlgorithm      rsa-sha256
AutoRestart             Yes

KeyTable is

nantes-1.p27.eu   p27.eu:mail:/etc/opendkim/p27.eu.key

SigningTable is

*@p27.eu                 nantes-1.p27.eu
*@transport-nantes.com   nantes-1.p27.eu

and TrustedHosts (which may not be needed) is

127.0.0.1

Any suggestions?

-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/
-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/
Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

ilyak
> The config file is active, however. 

You can check your milter config with

$  postconf smtpd_milters non_smtpd_milters milter_default_action

or even

$ postconf  | grep milter

You can probably post output it here.
Also, try to increase logging:


Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

Wietse Venema
In reply to this post by Jeff Abrahamson
Jeff Abrahamson:
> I've set up OpenDKIM.? I've noted the config below, but the basic issue
> is that my mails aren't being DKIM signed and my logs, while showing no
> mail-related errors, also don't show any evidence of milters running or
> trying to run.? So I'm suspecting postfix config error rather than
> opendkim.? So far all doc reading and googling is leading me nowhere
> immediately helpful.
>
> I'm trying to figure out what's wrong or at least how to debug it
> further.? (This is all on ubuntu 16.04.6 LTS.? I sadly need to get this

To debug OPENDKIM, ask the OPENDKIM forum.

But first, look at the output from this command:

postconf -n

and see if it shows the settings that you intended to use.

Ditto with the command "postconf -P" which shows parameter settings
in master.cf.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

Jeff Abrahamson
On 14/10/2020 16:06, Wietse Venema wrote:

> Jeff Abrahamson:
>> I've set up OpenDKIM.? I've noted the config below, but the basic issue
>> is that my mails aren't being DKIM signed and my logs, while showing no
>> mail-related errors, also don't show any evidence of milters running or
>> trying to run.? So I'm suspecting postfix config error rather than
>> opendkim.? So far all doc reading and googling is leading me nowhere
>> immediately helpful.
>>
>> I'm trying to figure out what's wrong or at least how to debug it
>> further.? (This is all on ubuntu 16.04.6 LTS.? I sadly need to get this
> To debug OPENDKIM, ask the OPENDKIM forum.
>
> But first, look at the output from this command:
>
> postconf -n
>
> and see if it shows the settings that you intended to use.
>
> Ditto with the command "postconf -P" which shows parameter settings
> in master.cf.

Thanks, and agreed about OpenDKIM forum.  As noted, the fact that the
milter appears not to be running suggests to me that I've made an error
on the postfix side.

Thanks for the reminder about postconf, recently mentioned by another
list member.

--
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/

Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

Jeff Abrahamson
In reply to this post by ilyak
On 14/10/2020 16:02, IL Ka wrote:
> The config file is active, however. 

You can check your milter config with

$  postconf smtpd_milters non_smtpd_milters milter_default_action

or even

$ postconf  | grep milter

You can probably post output it here.
Also, try to increase logging:

I've been playing with postconf this afternoon.  It's fun, but not telling me what I don't know.  (Here I've added a blank line between the two for readability):

[T] jeff@nantes-1:postfix $ postconf -P | grep milter
submission/inet/milter_macro_daemon_name = ORIGINATING
smtps/inet/milter_macro_daemon_name = ORIGINATING

[T] jeff@nantes-1:postfix $ postconf | grep milter
milter_command_timeout = 30s
milter_connect_macros = j {daemon_name} v
milter_connect_timeout = 30s
milter_content_timeout = 300s
milter_data_macros = i
milter_default_action = accept
milter_end_of_data_macros = i
milter_end_of_header_macros = i
milter_header_checks =
milter_helo_macros = {tls_version} {cipher} {cipher_bits} {cert_subject} {cert_issuer}
milter_macro_daemon_name = $myhostname
milter_macro_defaults =
milter_macro_v = $mail_name $mail_version
milter_mail_macros = "i {mail_addr} {client_addr} {client_name} {auth_type} {auth_authen}"
milter_protocol = 6
milter_rcpt_macros = i {rcpt_addr} {rcpt_host} {rcpt_mailer}
milter_unknown_command_macros =
non_smtpd_milters = $smtpd_milters
smtpd_milters = inet:127.0.0.1:8891
[T] jeff@nantes-1:postfix $

If I add -vvv I can see that non_smtpd_milters is set to the correct value (inet:127.0.0.1:8891).

I tried changing invocation to "smtpd -v" for both smtp and submission, but the send transaction doesn't change in any obvious way.

-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/
Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

ilyak
Shutdown OpenDKIM, set "milter_default_action = tempfail", reload postfix and try to send something.
If your mail is rejected, then Postfix configuration is ok, and you need to grep maillog (or other logs) for DKIM

On Wed, Oct 14, 2020 at 5:28 PM Jeff Abrahamson <[hidden email]> wrote:
On 14/10/2020 16:02, IL Ka wrote:
> The config file is active, however. 

You can check your milter config with

$  postconf smtpd_milters non_smtpd_milters milter_default_action

or even

$ postconf  | grep milter

You can probably post output it here.
Also, try to increase logging:

I've been playing with postconf this afternoon.  It's fun, but not telling me what I don't know.  (Here I've added a blank line between the two for readability):

[T] jeff@nantes-1:postfix $ postconf -P | grep milter
submission/inet/milter_macro_daemon_name = ORIGINATING
smtps/inet/milter_macro_daemon_name = ORIGINATING

[T] jeff@nantes-1:postfix $ postconf | grep milter
milter_command_timeout = 30s
milter_connect_macros = j {daemon_name} v
milter_connect_timeout = 30s
milter_content_timeout = 300s
milter_data_macros = i
milter_default_action = accept
milter_end_of_data_macros = i
milter_end_of_header_macros = i
milter_header_checks =
milter_helo_macros = {tls_version} {cipher} {cipher_bits} {cert_subject} {cert_issuer}
milter_macro_daemon_name = $myhostname
milter_macro_defaults =
milter_macro_v = $mail_name $mail_version
milter_mail_macros = "i {mail_addr} {client_addr} {client_name} {auth_type} {auth_authen}"
milter_protocol = 6
milter_rcpt_macros = i {rcpt_addr} {rcpt_host} {rcpt_mailer}
milter_unknown_command_macros =
non_smtpd_milters = $smtpd_milters
smtpd_milters = inet:127.0.0.1:8891
[T] jeff@nantes-1:postfix $

If I add -vvv I can see that non_smtpd_milters is set to the correct value (inet:127.0.0.1:8891).

I tried changing invocation to "smtpd -v" for both smtp and submission, but the send transaction doesn't change in any obvious way.

-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/
Reply | Threaded
Open this post in threaded view
|

Re: OpenDKIM but no log of postfix milter running or trying to run

Jeff Abrahamson

Oh, that's awesome, thanks.  So for the first time I got a log message concerning the milter.  And so this is, indeed, an OpenDKIM issue.

Many thanks, I'll go look over there for my problems.

Jeff Abrahamson

http://p27.eu/jeff/
http://transport-nantes.com/


On 14/10/2020 16:43, IL Ka wrote:

Shutdown OpenDKIM, set "milter_default_action = tempfail", reload postfix and try to send something.
If your mail is rejected, then Postfix configuration is ok, and you need to grep maillog (or other logs) for DKIM

On Wed, Oct 14, 2020 at 5:28 PM Jeff Abrahamson <[hidden email]> wrote:
On 14/10/2020 16:02, IL Ka wrote:
> The config file is active, however. 

You can check your milter config with

$  postconf smtpd_milters non_smtpd_milters milter_default_action

or even

$ postconf  | grep milter

You can probably post output it here.
Also, try to increase logging:

I've been playing with postconf this afternoon.  It's fun, but not telling me what I don't know.  (Here I've added a blank line between the two for readability):

[T] jeff@nantes-1:postfix $ postconf -P | grep milter
submission/inet/milter_macro_daemon_name = ORIGINATING
smtps/inet/milter_macro_daemon_name = ORIGINATING

[T] jeff@nantes-1:postfix $ postconf | grep milter
milter_command_timeout = 30s
milter_connect_macros = j {daemon_name} v
milter_connect_timeout = 30s
milter_content_timeout = 300s
milter_data_macros = i
milter_default_action = accept
milter_end_of_data_macros = i
milter_end_of_header_macros = i
milter_header_checks =
milter_helo_macros = {tls_version} {cipher} {cipher_bits} {cert_subject} {cert_issuer}
milter_macro_daemon_name = $myhostname
milter_macro_defaults =
milter_macro_v = $mail_name $mail_version
milter_mail_macros = "i {mail_addr} {client_addr} {client_name} {auth_type} {auth_authen}"
milter_protocol = 6
milter_rcpt_macros = i {rcpt_addr} {rcpt_host} {rcpt_mailer}
milter_unknown_command_macros =
non_smtpd_milters = $smtpd_milters
smtpd_milters = inet:127.0.0.1:8891
[T] jeff@nantes-1:postfix $

If I add -vvv I can see that non_smtpd_milters is set to the correct value (inet:127.0.0.1:8891).

I tried changing invocation to "smtpd -v" for both smtp and submission, but the send transaction doesn't change in any obvious way.

-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/
-- 
Jeff Abrahamson
+33 6 24 40 01 57
+44 7920 594 255

http://p27.eu/jeff/
http://transport-nantes.com/