search

fastmail / authentication_milter

Email Authentication by SPF/DKIM/DMARC etc.
Other
115 stars 20 forks source link

initial milter setup -- dkim scans/reports, but no SPF or ARC headers? #14

Closed ghost closed 5 years ago

ghost commented 5 years ago

I run Postfix 3.3.1.

I'm hoping to replace a working, but increasingly flaky, opendkim/opendmarc/policyspf setup with authentication_milter.

I've installed

    module_info Mail::Milter::Authentication Mail::AuthenticationResults Mail::DMARC::PurePerl

        Name:        Mail::Milter::Authentication
        Version:     undef
        Directory:   /usr/lib/perl5/site_perl/5.26.1
        File:        /usr/lib/perl5/site_perl/5.26.1/Mail/Milter/Authentication.pm
        Core module: no

        Name:        Mail::AuthenticationResults
        Version:     undef
        Directory:   /usr/lib/perl5/site_perl/5.26.1
        File:        /usr/lib/perl5/site_perl/5.26.1/Mail/AuthenticationResults.pm
        Core module: no

        Name:        Mail::DMARC::PurePerl
        Version:     undef
        Directory:   /usr/lib/perl5/site_perl/5.26.1
        File:        /usr/lib/perl5/site_perl/5.26.1/Mail/DMARC/PurePerl.pm
        Core module: no

I've def'd a systemd unit

    /etc/systemd/system/auth-milter.service
        [Unit]
        Description=AuthenticationMilter
        After=var-run.mount network-online.target remote-fs.target syslog.target

        [Service]
        Type=simple
        NonBlocking=yes
        PIDFile=/var/run/auth-milter/auth-milter.pid
        ExecStart=/usr/bin/authentication_milter -c start \
         --prefix=/usr/local/etc/auth-milter \
         --pidfile=/var/run/auth-milter/auth-milter.pid \
         --ident mx
        ExecReload=/bin/kill -USR1 $MAINPID
        ExecStop=/usr/bin/authentication_milter \
         -c stop \
         --prefix=/usr/local/etc/auth-milter \
         --pidfile=/var/run/auth-milter/auth-milter.pid

        [Install]
        WantedBy=multi-user.target

I've configured for milter use,

    /usr/local/etc/auth-milter/authentication_milter.json
        {
            "protocol"  : "milter",
            "debug"     : 0,
            "dryrun"    : 0,
            "logtoerr"  : 0,
            "error_log" : "/var/log/auth-milter/auth-milter.err",

            "connection" : "unix:/var/run/auth-milter/auth-milter.sock",
            "umask"      : "0000",
            "runas"      : "authmilter",
            "rungroup"   : "authmilter",
            "chroot"     : "",

            "listen_backlog"         : 20,
            "min_children"           : 5,
            "max_children"           : 25,
            "min_spare_children"     : 2,
            "max_spare_children"     : 5,
            "max_requests_per_child" : 100,

            "connect_timeout"       : 30,
            "command_timeout"       : 30,
            "content_timeout"       : 300,

            "dns_resolvers" : [
                "127.0.0.1"
            ],
            "dns_timeout"   : 10,
            "dns_retry"     : 2,

            "header_indent_style" : "entry",
            "header_fold_at"      : 77,
            "header_indent_by"    : 4,

            "tempfail_on_error"               : "1",
            "tempfail_on_error_authenticated" : "0",
            "tempfail_on_error_local"         : "0",
            "tempfail_on_error_trusted"       : "0",

            "handlers" : {

                "SPF" : {
                    "best_guess" : 0,
                    "hide_none"  : 0,
                    "hide_received-spf_header" : 0
                },

                "DKIM" : {
                    "hide_none" : 0,
                    "hide_domainkeys" : 1,
                    "check_adsp" : 1,
                    "show_default_adsp" : 0,
                    "adsp_hide_none" : 0
                },

                "DMARC" : {
                    "no_report" : "1",
                    "config_file" : "/usr/local/etc/auth-milter/mail-dmarc.ini",
                    "hard_reject" : 0,
                    "hide_none" : 0,
                    "no_reject_disposition" : "quarantine",
                    "detect_list_id" : "1",
                    "no_list_reject" : 0,
                    "no_list_reject_disposition" : "none",
                    "whitelisted"           : [
                        "dkim:bad.forwarder.com"
                    ],
                    "use_arc" : 1,
                    "report_skip_to" : [
                        "postmaster@example.com"
                    ]
                },

                "PTR" : {},

                "SenderID" : {
                    "hide_none" : 1
                },

                "IPRev" : {},

                "Auth" : {},

                "LocalIP" : {},

                "TrustedIP" : {
                    "trusted_ip_list" : [
                    ]
                },

                "!AddID" : {},

                "ReturnOK" : {},

                "Sanitize" : {
                    "hosts_to_remove" : [
                        "example.com",
                        "example.net"
                    ],
                    "remove_headers" : "yes"
                }
            }
        }

On daemon start

    systemctl start auth-milter

runs

    ps aux | grep -i authen
        authmil+ 26304  0.1  0.9 188596 79488 ?        Ss   13:14   0:00 authentication_milter_mx:master              
        authmil+ 26305  0.0  0.9 188728 76056 ?        S    13:14   0:00 authentication_milter_mx:waiting(1)          
        authmil+ 26306  0.0  0.8 188596 73400 ?        S    13:14   0:00 authentication_milter_mx:waiting(0)          
        authmil+ 26307  0.0  0.8 188596 72936 ?        S    13:14   0:00 authentication_milter_mx:waiting(0)          
        authmil+ 26308  0.0  0.8 188596 72936 ?        S    13:14   0:00 authentication_milter_mx:waiting(0)          
        authmil+ 26309  0.0  0.8 188596 72936 ?        S    13:14   0:00 authentication_milter_mx:waiting(0)

& logs

    tail -f /var/log/auth-milter/auth-milter.conf
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] daemonize servers=5/25 spares=2/5 requests=100
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] run as user=authmilter group=authmilter
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] Chroot to
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] listening on unix socket=/var/run/auth-milter/auth-milter.sock backlog=20
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] setting umask to 0000
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] ==========
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] Starting server
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] Running with perl v5.26.1
        Wed Oct 10 12:54:18 2018 authentication_milter_mx[25507] ==========

test-email sent from fastmail is received/delivered with headers,

    Authentication-Results: mx.example.net;
        dkim=pass (2048-bit rsa key sha256) header.d=fastmail.fm
          header.i=@fastmail.fm header.b=TgO1WPCB header.a=rsa-sha256
          header.s=fm1;
        dkim=pass (2048-bit rsa key sha256) header.d=messagingengine.com
          header.i=@messagingengine.com header.b=VmssBcQh header.a=rsa-sha256
          header.s=fm1;
        x-local-ip=pass;
        x-return-mx=pass header.domain=fastmail.fm policy.is_org=yes
          (MX Record found);
        x-return-mx=pass smtp.domain=fastmail.fm policy.is_org=yes
          (MX Record found)

with NO TRACE of spf, ARC ...

I'm comparing to messages received AT fastmail, which display (e.g.),

    Authentication-Results: mx5.messagingengine.com;
        arc=none (no signatures found);
        dkim=pass (1024-bit rsa key sha256) header.d=opayq.com
          header.i=@opayq.com header.b=ALCrBItS header.a=rsa-sha256
          header.s=abine x-bits=1024;
        dmarc=pass policy.published-domain-policy=none
          policy.published-subdomain-policy=none policy.applied-disposition=none
          policy.evaluated-disposition=none (p=none,sp=none,d=none,d.eval=none)
          header.from=opayq.com;
        iprev=pass policy.iprev=184.105.182.132
          (132-he.filtered.junkemailfilter.com);
        spf=pass smtp.mailfrom=FWD.xxxxxx@opayq.com
          smtp.helo=132-he.filtered.junkemailfilter.com;
        x-aligned-from=pass (Address match);
        x-cm=none score=0;
        x-ptr=pass smtp.helo=132-he.filtered.junkemailfilter.com
          policy.ptr=132-he.filtered.junkemailfilter.com;
        x-return-mx=pass header.domain=opayq.com policy.is_org=yes
          (MX Record found);
        x-return-mx=pass smtp.domain=opayq.com policy.is_org=yes
          (MX Record found);
        x-tls=pass smtp.version=TLSv1.2 smtp.cipher=ECDHE-RSA-AES128-GCM-SHA256
          smtp.bits=128/128;
        x-vs=clean score=0 state=0

I'm guessing I'm missing SPF & ARC 'parts'?

I'm unclear on what's missing/misconfigured here.

Any guidance is appreciated.

Better yet, Is there a thorough example/walk-thru of setting this all up?

marcbradshaw commented 5 years ago

Hi @pgd151 ,

SPF was not added in this case as the connection to the MTA came from a local IP address, in this case any checks which require global IP addresses are skipped, including SPF. If you connect to the MTA from a globally routable IP address then SPF entries should be added.

The ARC handler is not currently a part of the main install, and will need to be install separately. The CPAN module you will need for this is Mail::Milter::Authentication::Handler::ARC

Once this is installed you can add a ARC config in the handler section of the main config file.

Example from the ARC handler docs.

"ARC" : { | Config for the ARC Module "hide_none" : 0, | Hide auth line if the result is 'none' "arcseal_domain" : "example.com", | Domain to sign ARC Seal with (not sealed if blank) "arcseal_selector" : undef, | Selector to use for ARC Seal (not sealed if blank) "arcseal_algorithm" : 'rsa-sha256', | Algorithm to use on ARC Seal (default rsa-sha256) "arcseal_key" : undef, | Key (base64) string to sign ARC Seal with; or "arcseal_keyfile" : undef, | File containing ARC Seal key "arcseal_headers" : undef, | Additional headers to cover in ARC-Message-Signature "trusted_domains" : [], | Trust these domains when traversing ARC chains "rbl_whitelist" : undef, | rhs list for looking up trusted signing domains "no_strict" : 0, | Ignore rfc 8301 security considerations (not recommended) },

In order to enable ARC sealing you will need to create a key pair, and publish the public part in the DNS in the same way as publishing a DKIM key.

For a list of trusted domains I suggest you look at the list published by the trusted domain project here https://github.com/trusteddomainproject/ARC_Community_Sealers You can either configure this using trusted_domains, or by publishing into the DNS and using rbl_whitelist, the dns method is currently experimental, and being explored as an option.

A couple of other comments...

You may want to check which version of Mail::DKIM your system has installed. The some linux distributions often come with older versions without support for ARC.

The dkim:bad.forwarder.com entry in your DMARC config is an example only, and can safely be removed.

The Sanitize section should contain an entry for your own domain, this will remove any Authentication Results headers coming in falsely claiming to be from your own domain.

I would love to be able to say there was a walkthrough or guide for setting this up, but unfortunately this doesn't yet exist. Any feedback into the pain points of setting up would be helpful in getting this written.

Thanks,

ghost commented 5 years ago

hi marc,

SPF was not added in this case as the connection to the MTA came from a local IP address, in this case any checks which require global IP addresses are skipped, including SPF. If you connect to the MTA from a globally routable IP address then SPF entries should be added.

Here, a Postfix internal smtpd instance passes inbound mail 1st to an amavisd PREQUEUE instance, listening on localhost:20000

    /etc/postfix/master.cf
        [mx.example.net.net]:25  inet  n  -   n        -        1       postscreen
         -o postscreen_tls_security_level=may
         -o smtpd_service_name=postscreen-internal

        postscreen-internal  pass  -     -        n        -        -       smtpd
          -o syslog_name=postfix/postscreen-internal
          -o smtpd_relay_restrictions=permit_mynetworks,reject_unauth_destination,permit
          -o smtpd_proxy_filter=127.0.0.1:20000
          -o smtpd_authorized_xforward_hosts=127.0.0.0/8
        ...

after doing some initial header/extension processing, amavisd returns it, still PREQUEUE, forwarding to localhost:11030,

    /etc/amavisd/amavisd.conf
        ...
        $interface_policy{'20000'} = 'IN-PREQ';
        $policy_bank{'IN-PREQ'} = {
          protocol => 'SMTP',
          forward_method => 'smtp:[127.0.0.1]:11030', # reinject
        ...

and postifx deals with it there, passing -- finally -- to the authentication_milter instance, among others

    /etc/postfix/master.cf
        ...
        [127.0.0.1]:11030 inet n        -        n        -        -       smtpd
          -o smtpd_banner=localhost.11030
          -o syslog_name=postfix/in-preq
          -o milter_protocol=6
          -o smtpd_milters=unix:/var/run/clamav/clamav-milter.socket,unix:/var/run/auth-milter/auth-milter.sock,unix:/var/run/milter-regex/milter-regex.sock
        ...

So, the authentication_milter IS seeing the email 'from' localhost.

This has been working for ages with opendkim configured in the middle of this mess.

How/where do I config authentication_milter to allow this internal pass, preserving the 'real' IP source data?

The CPAN module you will need for this isMail::Milter::Authentication::Handler::ARC

now installed,

    module_info Mail::Milter::Authentication::Handler::ARC
        Name:        Mail::Milter::Authentication::Handler::ARC
        Version:     undef
        Directory:   /usr/lib/perl5/site_perl/5.26.1
        File:        /usr/lib/perl5/site_perl/5.26.1/Mail/Milter/Authentication/Handler/ARC.pm
        Core module: no

Once this is installed you can add a ARC config in the handler section of the main config file.

OK, I've added initially,

        "ARC" : {
            "hide_none" : 0,
            "arcseal_domain" : "example.net",
            "arcseal_selector" : "undef",
            "arcseal_algorithm" : "rsa-sha256",
            "arcseal_key" : "undef",
            "arcseal_keyfile" : "undef",
            "arcseal_headers" : "undef",
            "trusted_domains" : [],
            "rbl_whitelist" : "undef",
            "no_strict" : 0
        },

OpenARC's an eventual/nice-to-have.

I'll concern myself with SPF first, until I get this

In order to enable ARC sealing you will need to create a key pair, and publish the public part in the DNS in the same way as publishing a DKIM key.

done.

You may want to check which version of Mail::DKIM your system has installed. The some linux distributions often come with older versions without support for ARC.

module_info Mail::DKIM
    Name:        Mail::DKIM
    Version:     undef
    Directory:   /usr/lib/perl5/site_perl/5.26.1
    File:        /usr/lib/perl5/site_perl/5.26.1/Mail/DKIM.pm

undef?

perl -le 'eval "require $ARGV[0]" and print $ARGV[0]->VERSION' Mail::DKIM
    0.53

The dkim:bad.forwarder.com entry in your DMARC config is an example only, and can safely be removed.

noted

The Sanitize section should contain an entry for your own domain, this will remove any Authentication Results headers coming in falsely claiming to be from your own domain.

yep. just hand't gotten there. that'll be joined by a "how to" question of using signing tables -- different sigs, etc for different inbound & outbound domains (again, as implemented in opendkim)

Any feedback into the pain points of setting up would be helpful in getting this written.

Glad you're open to it!

Once I get this all satisfactorily working a 'first time', a procedure -- with pain points! -- should fall out of it.

ghost commented 5 years ago

ironically, even with my 'initial' hacked config for ARC, messages ARE now being header-tagged with:

    arc=none (no signatures found);

No SPF. yet ...

marcbradshaw commented 5 years ago

It's not clear from the configs, but it could be that the xforward information isn't going through the entire chain of SMTP filters, if there anything in logs which could suggest where postfix starts to see localhost? In milter protocol mode the address comes directly from the calling postfix instance.

ghost commented 5 years ago

In milter protocol mode the address comes directly from the calling postfix instance.

Right. And here, my opendkim instance is (well, was) getting all the x-forward info -- properly processing and reporting SPF/DMARC results.

Atm, I've simply replaced its socked with that that of auth-milter, in postfix config.

I.e., this multi-milter chain config,

-o smtpd_milters=unix:/var/run/clamav/clamav-milter.socket,unix:/var/run/opendkim/opendkim.sock,unix:/var/run/opendmarc/opendmarc.sock,unix:/var/run/milter-regex/milter-regex.sock

works, but, this

-o smtpd_milters=unix:/var/run/clamav/clamav-milter.socket,unix:/var/run/auth-milter/auth-milter.sock,unix:/var/run/milter-regex/milter-regex.sock

doesn't currently.

ghost commented 5 years ago

Here's the current full postfix log for an inbound (from fastmail) message:

Connect from outside to Postfix's postscreen

Oct 10 14:52:04 mx.example.net postfix/postscreen[35045]: CONNECT from [66.111.4.27]:59357 to [MY.MX.REAL.IP]:25
Oct 10 14:52:04 mx.example.net postfix/postscreen[35045]: PASS OLD [66.111.4.27]:59357

handoff to internal Postfix smtpd instance

Oct 10 14:52:04 mx.example.net postfix/postscreen-internal/smtpd[35051]: connect from out3-smtp.messagingengine.com[66.111.4.27]
Oct 10 14:52:04 mx.example.net postfix/postscreen-internal/smtpd[35051]: Anonymous TLS connection established from out3-smtp.messagingengine.com[66.111.4.27]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Oct 10 14:52:06 mx.example.net postfix/postscreen-internal/smtpd[35051]: NOQUEUE: client=out3-smtp.messagingengine.com[66.111.4.27]

to/from the milters,

Oct 10 14:52:06 mx.example.net postfix/in-preq/smtpd[35143]: connect from localhost[127.0.0.1]
Oct 10 14:52:06 mx.example.net postfix/in-preq/smtpd[35143]: 42Vp8G3PQqz15K0: client=localhost[127.0.0.1], orig_client=out3-smtp.messagingengine.com[66.111.4.27]
Oct 10 14:52:06 mx.example.net postfix/cleanup[35054]: 42Vp8G3PQqz15K0: message-id=<6b35f1b8-335a-3482-7d9b-11b6b8fdd079@fastmail.fm>
Oct 10 14:52:06 mx.example.net authentication_milter_mx[34790]: 42Vp8G3PQqz15K0: SetSymbol: C: v: Postfix 3.3.1
Oct 10 14:52:06 mx.example.net postfix/qmgr[24924]: 42Vp8G3PQqz15K0: from=<testXXXXfastmail.fm>, size=3341, nrcpt=1 (queue active)
Oct 10 14:52:06 mx.example.net postfix/in-preq/smtpd[35143]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 quit=1 commands=6
Oct 10 14:52:06 mx.example.net postfix/postscreen-internal/smtpd[35051]: proxy-accept: END-OF-MESSAGE: 250 2.0.0 from MTA(smtp:[127.0.0.1]:11030): 250 2.0.0 Ok: queued as 42Vp8G3PQqz15K0; from=<testXXXXfastmail.fm> to=<postmaster@example.com> proto=ESMTP helo=<out3-smtp.messagingengine.com>
Oct 10 14:52:06 mx.example.net postfix/postscreen-internal/smtpd[35051]: disconnect from out3-smtp.messagingengine.com[66.111.4.27] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Oct 10 14:52:08 mx.example.net postfix/in-postq/smtpd[35148]: connect from localhost[127.0.0.1]
Oct 10 14:52:08 mx.example.net postfix/in-postq/smtpd[35148]: 42Vp8J0MxBz15sh: client=localhost[127.0.0.1], orig_queue_id=42Vp8G3PQqz15K0, orig_client=out3-smtp.messagingengine.com[66.111.4.27]
Oct 10 14:52:08 mx.example.net postfix/cleanup[35054]: 42Vp8J0MxBz15sh: message-id=<6b35f1b8-335a-3482-7d9b-11b6b8fdd079@fastmail.fm>
Oct 10 14:52:08 mx.example.net postfix/qmgr[24924]: 42Vp8J0MxBz15sh: from=<testXXXXfastmail.fm>, size=5602, nrcpt=1 (queue active)
Oct 10 14:52:08 mx.example.net postfix/in-postq/smtpd[35148]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 quit=1 commands=6
Oct 10 14:52:08 mx.example.net postfix/amavis-feed/smtp[35144]: 42Vp8G3PQqz15K0: to=<postmaster@example.com>, relay=127.0.0.1[127.0.0.1]:20002, delay=1.6, delays=0.07/0.02/0/1.5, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:11031): 250 2.0.0 Ok: queued as 42Vp8J0MxBz15sh)
Oct 10 14:52:08 mx.example.net postfix/qmgr[24924]: 42Vp8G3PQqz15K0: removed

final relay to internal smtp, eventual imap delivery

Oct 10 14:52:08 mx.example.net postfix/relayin/smtp[35055]: 42Vp8J0MxBz15sh: to=<postmaster@example.com>, relay=internal.mx.example.net[10.1.11.106]:41443, delay=0.66, delays=0/0/0.28/0.37, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 66D9680445)
Oct 10 14:52:08 mx.example.net postfix/qmgr[24924]: 42Vp8J0MxBz15sh: removed
ghost commented 5 years ago

I notice in my received msg headers

Authentication-Results: mx.example.net;
    arc=none (no signatures found);
    ...

Where "mx.example.net" is my real/external hostname ... NOT the AuthServID of the passing instance.

In opendkim, amavis, opendmarc, etc instances, I set that value.

For auth milter, I see

https://metacpan.org/pod/Mail::AuthenticationResults::Header::AuthServID
https://metacpan.org/pod/Mail::AuthenticationResults::Header::Base

exists, but usage isn't specified.

I assume the AuthServID goes 'somewhere' in the .json config?

I think what I'm looking for here is the equivalent of Opendmarc's

TrustedAuthservIDs

which lists the trusted AuthServ-IDs as spec'd in

"Authentication Identifier Field https://tools.ietf.org/html/rfc7601#section-2.5

ghost commented 5 years ago

After supposedly cleaning up some more config, for an inbound message, logs appear to show SPF & DMARC processing,

Oct 10 16:36:31 mx.example.net postfix/postscreen[38415]: CONNECT from [66.111.4.27]:39373 to [MY.MX.REAL.IP]:25
Oct 10 16:36:31 mx.example.net postfix/dnsblog[38416]: addr 66.111.4.27 listed by domain list.dnswl.org as 127.0.5.1
Oct 10 16:36:32 mx.example.net postfix/postscreen[38415]: PASS OLD [66.111.4.27]:39373
Oct 10 16:36:32 mx.example.net postfix/postscreen-internal/smtpd[38420]: connect from out3-smtp.messagingengine.com[66.111.4.27]
Oct 10 16:36:32 mx.example.net postfix/postscreen-internal/smtpd[38420]: Anonymous TLS connection established from out3-smtp.messagingengine.com[66.111.4.27]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Oct 10 16:36:33 mx.example.net postfix/postscreen-internal/smtpd[38420]: NOQUEUE: client=out3-smtp.messagingengine.com[66.111.4.27]
Oct 10 16:36:33 mx.example.net postfix/in-preq/smtpd[38424]: connect from localhost[127.0.0.1]
Oct 10 16:36:33 mx.example.net postfix/in-preq/smtpd[38424]: 41ZeAC3FkGz14r7: client=localhost[127.0.0.1], orig_client=out3-smtp.messagingengine.com[66.111.4.27]
Oct 10 16:36:33 mx.example.net postfix/cleanup[38425]: 41ZeAC3FkGz14r7: message-id=<d8f4ff49-22be-c5b1-2fc4-670805cef482@fastmail.fm>
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Setup SPF
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: SetSymbol: C: v: Postfix 3.3.1
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Helo DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Helo SPF
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EnvFrom ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EnvFrom DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: Object set: dmarc
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: Object set: dmarc
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EnvFrom SPF
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EnvFrom DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EnvRcpt DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Header DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EOH ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: ARCResult: No ARC headers
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EOH DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: Object set: dkim
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Body ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Body DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EOM DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMResult: pass
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureType: dkim
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureDomain: fastmail.fm
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureIdentity: @fastmail.fm
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureResult: pass
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureType: dkim
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureDomain: messagingengine.com
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureIdentity: @messagingengine.com
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: DKIMSignatureResult: pass
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EOM ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: EOM DMARC
                                                                              arc=none (no signatures found);
                                                                              dkim=pass (2048-bit rsa key sha256) header.d=fastmail.fm
                                                                              dkim=pass (2048-bit rsa key sha256) header.d=messagingengine.com
Oct 10 16:36:33 mx.example.net postfix/qmgr[24924]: 41ZeAC3FkGz14r7: from=<testXXX@fastmail.fm>, size=3341, nrcpt=1 (queue active)
Oct 10 16:36:33 mx.example.net postfix/in-preq/smtpd[38424]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 quit=1 commands=6
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Close ARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Close DKIM
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: Object destroyed: dkim
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Close DMARC
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: Object destroyed: dmarc
Oct 10 16:36:33 mx.example.net authentication_milter_mx[38410]: 41ZeAC3FkGz14r7: CALLBACK: Close SPF
Oct 10 16:36:33 mx.example.net postfix/postscreen-internal/smtpd[38420]: proxy-accept: END-OF-MESSAGE: 250 2.0.0 from MTA(smtp:[127.0.0.1]:11030): 250 2.0.0 Ok: queued as 41ZeAC3FkGz14r7; from=<testXXX@fastmail.fm> to=<postmaster@example.com> proto=ESMTP helo=<out3-smtp.messagingengine.com>
Oct 10 16:36:34 mx.example.net postfix/postscreen-internal/smtpd[38420]: disconnect from out3-smtp.messagingengine.com[66.111.4.27] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Oct 10 16:36:35 mx.example.net postfix/in-postq/smtpd[38430]: connect from localhost[127.0.0.1]
Oct 10 16:36:35 mx.example.net postfix/in-postq/smtpd[38430]: 42VrZb4Gknz15sh: client=localhost[127.0.0.1], orig_queue_id=41ZeAC3FkGz14r7, orig_client=out3-smtp.messagingengine.com[66.111.4.27]
Oct 10 16:36:35 mx.example.net postfix/cleanup[38425]: 42VrZb4Gknz15sh: message-id=<d8f4ff49-22be-c5b1-2fc4-670805cef482@fastmail.fm>
Oct 10 16:36:35 mx.example.net postfix/qmgr[24924]: 42VrZb4Gknz15sh: from=<testXXX@fastmail.fm>, size=5602, nrcpt=1 (queue active)
Oct 10 16:36:35 mx.example.net postfix/in-postq/smtpd[38430]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 quit=1 commands=6
Oct 10 16:36:35 mx.example.net postfix/amavis-feed/smtp[38426]: 41ZeAC3FkGz14r7: to=<postmaster@example.com>, relay=127.0.0.1[127.0.0.1]:20002, delay=1.7, delays=0.06/0.01/0/1.7, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:11031): 250 2.0.0 Ok: queued as 42VrZb4Gknz15sh)
Oct 10 16:36:35 mx.example.net postfix/qmgr[24924]: 41ZeAC3FkGz14r7: removed
Oct 10 16:36:37 mx.example.net postfix/relay-vpn/smtp[38431]: 42VrZb4Gknz15sh: to=<postmaster@example.com>, relay=internal.mx.example.net[10.1.11.106]:41443, delay=2, delays=0/0.01/1.5/0.49, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5087D80460)
Oct 10 16:36:37 mx.example.net postfix/qmgr[24924]: 42VrZb4Gknz15sh: removed

but results are lacking any trace of it,

Authentication-Results: mx.example.net;
    arc=none (no signatures found);
    dkim=pass (2048-bit rsa key sha256) header.d=fastmail.fm
      header.i=@fastmail.fm header.b=V+7AxBoh header.a=rsa-sha256
      header.s=fm1;
    dkim=pass (2048-bit rsa key sha256) header.d=messagingengine.com
      header.i=@messagingengine.com header.b=mCtuI4GP header.a=rsa-sha256
      header.s=fm1;
    x-local-ip=pass;
    x-return-mx=pass header.domain=fastmail.fm policy.is_org=yes
      (MX Record found);
    x-return-mx=pass smtp.domain=fastmail.fm policy.is_org=yes
      (MX Record found);
    x-trusted-ip=pass

still looking to identify/allow that localhost issue you mentioned ...

marcbradshaw commented 5 years ago

Not sure what's going on there. I'll run up a test system with similar config and do some debugging.

ghost commented 5 years ago

I'm getting somewhat suspicious of my setup atm ...

Particularly, mail-dmarc.ini is getting ignored.

Or, at least, with

dsn     = dbi:SQLite:dbname=/usr/local/etc/auth-milter/dmarc_reports.sqlite

specified, I'm seeing no errors on auth milter restart, but I'm not getting the DB created.

scratching my head now as to whether this indicates noob-pebkac, or something more problematic ....

fwiw, https://github.com/msimerson/mail-dmarc/issues/136

ghost commented 5 years ago

if there's debug info from my end that'd be helpful, pls specify. i'm still at the WTF-is-going-here-ish stage ;-)

marcbradshaw commented 5 years ago

Hi @pgd151 ,

The issue is that postfix can't pass the correct IP to the milter when it is not the instance which accepted the original connection. I don't think there is an easy fix for this given the current architecture.

There are 2 ways to fix this with your install.

1) Move the milter calls to authentication_milter to the instance of postfix which accepts the original connection.

or

2) Use authentication_milter in SMTP filtering mode, you could do this by having amavisd connect to authentication_milter, and then have authentication_milter connect back to postfix (or vice versa). This will then use the xforward headers to find the correct IP.

ghost commented 5 years ago

postfix can't pass the correct IP to the milter

I'm missing something ...

Can you explain then how opendkim & opendmarc manage to work and add headers when, either together or separately, they replace auth-milter in that^ milter chain?

ghost commented 5 years ago

Response from the Postfix author:

The IP address is propagated to the Milter as part of the SMFIC_CONNECT
event.

Therefore, configure the Milter with the SMTPD process that talks   
to the IP address in question.

Not exactly sure yet what to DO with that ...

marcbradshaw commented 5 years ago

Hi @pgd151

opendkim doesn't validate, or use spf, so it doesn't need the connecting IP. opendmarc doesn't validate spf, it relies on something earlier in the chain adding an SPF header to the message. Something earlier in the chain (amivisd perhaps) could be validating the SPF, as this is configured as an SMTP filter it would have access to the xforward information with the original IP address intact.

The postfix author is saying the same as option 1 above, the first instance of postfix passes the correct IP using milter protocol, subsequent ones only pass localhost. So for a milter protocol you need to use the first postfix in the chain, or use smtp filtering which has access to xforward information.

ghost commented 5 years ago

@marcbradshaw

got it -- thanks for the patience! switching to smtp mode for auth-milter. getting a different set of nits, atm:

 warning: milter unix:/var/run/auth-milter/auth-milter.sock: unexpected reply "s" in initial handshake

but I'll get that sorted!

p.s. what do you &/or fastmail typically use for outbound dkim signing?

Sailfish33 commented 5 years ago

Thank you

On Sun, Oct 14, 2018 at 18:49 pgd151 notifications@github.com wrote:

@marcbradshaw https://github.com/marcbradshaw

got it -- thanks for the patience! switching to smtp mode for auth-milter. getting a different set of nits, atm:

warning: milter unix:/var/run/auth-milter/auth-milter.sock: unexpected reply "s" in initial handshake

but I'll get that sorted!

p.s. what do you &/or fastmail typically use for outbound dkim signing?

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/fastmail/authentication_milter/issues/14#issuecomment-429670118, or mute the thread https://github.com/notifications/unsubscribe-auth/AVtHzERKK9J_Wvf5IUxZjev0YRWLtz1Eks5uk7-BgaJpZM4XWQwq .

marcbradshaw commented 5 years ago

The config for auth-milter is a little different when running in smtp mode, protocol should be set to smtp, and an smtp section added with details of the mode (before or after queue) and re-injection setting back to postfix, "perldoc authentication_milter" will give you an example. DKIM signing in FastMail uses Mail::DKIM but the code calling that is custom

ghost commented 5 years ago

Sure, got that config switched already. Docs are nice & clear. Still getting that silly error ...

Rats, re: 'custom'. Looking for a good option. Thx again.