Ich hatte kürzlich einen Mailserver komplett neu aufgesetzt und gestern final in Betrieb genommen. Soweit klappte alles recht gut, nur wunderte ich mich, dass bei diversen Testmails keinerlei Hinweise im Header bzgl. Amavis-Tätigkeiten zu finden waren. Also schade ich in das Log und sah Meldungen der folgenden Art:


Dec 4 17:20:04 mx postfix/postscreen[1755]: CONNECT from [193.239.107.41]:58241 to [193.239.107.52]:25
Dec 4 17:20:04 mx postfix/postscreen[1755]: PASS OLD [193.239.107.41]:58241
Dec 4 17:20:04 mx postfix/smtpd[2122]: connect from mx0.roessner-net.de[193.239.107.41]:58241
Dec 4 17:20:04 mx postfix/smtpd[2122]: Anonymous TLS connection established from mx0.roessner-net.de[193.239.107.41]:58241: TLSv1
.2 with cipher AECDH-AES256-SHA (256/256 bits)
Dec 4 17:20:04 mx postfix/smtpd[2122]: 3dZQJN586Lz1DlG: client=mx0.roessner-net.de[193.239.107.41]:58241
Dec 4 17:20:04 mx postfix/cleanup[2104]: 3dZQJN586Lz1DlG: message-id= ions.com>
Dec 4 17:20:04 mx amavis[3476]: loaded policy bank "AM.PDP-SOCK"
Dec 4 17:20:04 mx amavis[3476]: (03476) Request: AM.PDP /var/amavis/tmp/afXXXXLCV9qS: -> deltaweb.de>
Dec 4 17:20:04 mx amavis[3476]: (03476) dkim: VALID Author+Sender+MailFrom signature by d=roessner-network-solutions.com, From: < c@roessner-network-solutions.com>, a=rsa-sha256, c=relaxed/simple, s=s0, i=@roessner-network-solutions.com
Dec 4 17:20:04 mx amavis[3476]: (03476) Checking: hjT98L3w0Swl AM.PDP-SOCK [193.239.107.41] ->

—->
Dec 4 17:20:04 mx amavis[3476]: (03476) Open relay? Nonlocal recips but not originating: cr@deltaweb.de
< —-

Dec 4 17:20:04 mx amavis[3476]: (03476) p003 1 Content-Type: multipart/signed
Dec 4 17:20:04 mx amavis[3476]: (03476) p001 1/1 Content-Type: text/plain, size: 219 B, name:
Dec 4 17:20:04 mx amavis[3476]: (03476) p002 1/2 Content-Type: application/pkcs7-signature, size: 3089 B, name: smime.p7s
Dec 4 17:20:09 mx amavis[3476]: (03476) SA info: pyzor: [3995] error: TERMINATED, signal 15 (000f)
Dec 4 17:20:09 mx amavis[3476]: (03476) DSPAM result: Innocent, score=-1.000, sig=529f563940085795210622

—->
Dec 4 17:20:09 mx amavis[3476]: (03476) Passed CLEAN {AcceptedOpenRelay}, AM.PDP-SOCK [193.239.107.41] [193.239.106.201] -> , Queue-ID: 3dZQJN586Lz1DlG, Message-ID: , mail_id: hjT98L3w0Swl, Hits: -1.1, size: 6392, dkim_sd=s0:roessner-network-solutions.com, 5015 ms
Dec 4 17:20:09 mx amavis[3476]: (03476) TIMING-SA total 4730 ms – parse: 4 (0.1%), extract_message_metadata: 7 (0.1%), get_uri_detail_list: 3 (0.1%), tests_pri_-1000: 10 (0.2%), tests_pri_-950: 1.19 (0.0%), tests_pri_-900: 1.34 (0.0%), tests_pri_-400: 0.93 (0.0%), tests_pri_0: 4604 (97.3%), check_razor2: 503 (10.6%), check_pyzor: 4012 (84.8%), tests_pri_500: 5 (0.1%), learn: 56 (1.2%), get_report: 1.10 (0.0%)
< —-

Dec 4 17:20:09 mx amavis[3476]: (03476) mail checking ended: version_server=2\nlog_id=03476\nsetreply=250 2.5.0 Ok,%20id=03476,%20continue%20delivery\nreturn_value=continue\nexit_code=0
Dec 4 17:20:09 mx amavisd-milter[4579]: 3dZQJN586Lz1DlG: log_id=03476
Dec 4 17:20:09 mx amavisd-milter[4579]: 3dZQJN586Lz1DlG: return_value=continue
Dec 4 17:20:09 mx amavis[3476]: (03476) size: 6392, TIMING [total 5034 ms] – got data: 0 (0%)0, check_init: 10 (0%)0, digest_hdr: 11 (0%)0, digest_body_dkim: 19 (0%)1, sql-connect: 20 (0%)1, gen_mail_id: 19 (0%)2, sql-connect: 5 (0%)2, lookup_sql: 1 (0%)2, mkdir parts: 1 (0%)2, mime_decode: 24 (0%)2, get-file-type2: 39 (1%)3, parts_decode: 1 (0%)3, check_header: 2 (0%)3, AV-scan-1: 22 (0%)3, spam-wb-list: 1 (0%)3, SA msg read: 2 (0%)4, SA parse: 12 (0%)4, SA check: 4719 (94%)98, DSPAM: 83 (2%)99, decide_mail_destiny: 4 (0%)99, notif-quar: 1 (0%)99, prepare-dsn: 4 (0%)99, main_log_entry: 16 (0%)100, sql-update: 5 (0%)100, update_snmp: 3 (0%)100, rundown: 7 (0%)100
Dec 4 17:20:09 mx postfix/qmgr[1739]: 3dZQJN586Lz1DlG: from=<c@roessner-network-solutions.com>, size=6518, nrcpt=1 (queue active)
Dec 4 17:20:09 mx postfix/smtpd[2122]: disconnect from mx0.roessner-net.de[193.239.107.41]:58241
Dec 4 17:20:09 mx amavis[3476]: (03476) extra modules loaded: unicore/lib/Gc/Nd.pl
Dec 4 17:20:09 mx postfix/lmtp[1863]: 3dZQJN586Lz1DlG: to=, relay=::1[::1]:24, delay=5.1, delays=5.1/0/0/0.03, dsn=2.0.0, status=sent (250 2.0.0 VIeDEARWn1KdDgAAE8C+Wg Saved)

Ich suchte ewig in der Konfiguration nach, um letztlich herauszufinden, dass der Parameter local_domains_maps essentiell wichtig ist. Mein eigener Mailserver und auch der eines Kollegen verwenden LDAP als Datenbank und benötigen diesen Parameter nicht. Der hier gezeigte Mailserver nutzt lediglich eine MySQL-Datenbank und braucht daher diese Option.

Hier ein kurzer Auszug, welche Parameter wichtig für amavisd-milter sind:

# amavisd-milter
$protocol = "AM.PDP";
$inet_socket_port = undef;
$unix_socketname = "$MYHOME/amavisd.sock";

$interface_policy{'SOCK'} = 'AM.PDP-SOCK';

# Important! The following parameter is required for amavisd. Without it, you
# get AcceptedOpenRelay messages in the logs and no checks are applied!
@local_domains_maps = ( "." );

$policy_bank{'AM.PDP-SOCK'} = {
  auth_required_release => 0,
};