Mail problems after latest ISPC3 update

I just ran the upgrade script to update to 3.0.5.4p9 from 3.0.5.4p8. After updating, I started receiving deferred mails. I found that amavisd was not running so I started that and restarted postfix. I'm still getting deferred messages, now with a different error. The mail log shows the following.

Code:

Apr 15 18:09:37 myhost postfix/error[21484]: 3AE813E04F5C: to=<[email protected]>, relay=none, delay=1264, delays=1264/0.05/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting)
a.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=4059, delays=4059/0.02/0.01/0, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting)
Apr 15 18:09:37 myhost postfix/smtp[21478]: 4D76E3E04F5E: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, delay=679, delays=678/0.03/0/0, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting)
Apr 15 18:09:37 myhost amavis[19611]: (!)DENIED ACCESS from IP 123.456.789.123, policy bank ''

I've removed my host name and email addresses. The IP 123.456.789.123 is the correct IP address for my server.
I'm using the Perfect Server setup on CentOS 6. A portion of amavisd looks like this.

Code:

@mynetworks = qw( 127.0.0.0/8 [::1] [FE80::]/10 [FEC0::]/10
                  10.0.0.0/8 172.16.0.0/12 192.168.0.0/16 );

$unix_socketname = "$MYHOME/amavisd.sock";  # amavisd-release or amavis-milter
               # option(s) -p overrides $inet_socket_port and $unix_socketname

$inet_socket_port = 10024;   # listen on this local TCP port(s)
# $inet_socket_port = [10024,10026];  # listen on multiple TCP ports

$policy_bank{'MYNETS'} = {   # mail originating from @mynetworks
  originating => 1,  # is true in MYNETS by default, but let's make it explicit
  os_fingerprint_method => undef,  # don't query p0f for internal clients
};

# it is up to MTA to re-route mail from authenticated roaming users or
# from internal hosts to a dedicated TCP port (such as 10026) for filtering
$interface_policy{'10026'} = 'ORIGINATING';

$policy_bank{'ORIGINATING'} = {  # mail supposedly originating from our users
  originating => 1,  # declare that mail was submitted by our smtp client
  allow_disclaimers => 1,  # enables disclaimer insertion if available
  # notify administrator of locally originating malware
  virus_admin_maps => ["virusalert\@$mydomain"],
  spam_admin_maps  => ["virusalert\@$mydomain"],
  warnbadhsender   => 1,
  # forward to a smtpd service providing DKIM signing service
  forward_method => 'smtp:[127.0.0.1]:10027',
  # force MTA conversion to 7-bit (e.g. before DKIM signing)
  smtpd_discard_ehlo_keywords => ['8BITMIME'],
  bypass_banned_checks_maps => [1],  # allow sending any file names and types
  terminate_dsn_on_notify_success => 0,  # don't remove NOTIFY=SUCCESS option
};

 

I tried adding my IP address to mynetworks and restarting amavisd and postfix but it did not work.

Code:

@mynetworks = qw( 123.456.789.123 127.0.0.0/8 [::1] [FE80::]/10 [FEC0::]/10
                  10.0.0.0/8 172.16.0.0/12 192.168.0.0/16 );

But again, this all worked perfectly before the update.

 

I do not have that plugin installed.

 

I checked with netstat -tap and both postfix and amavis are listening on their respective ports.

Code:

tcp        0      0 *:smtp                      *:*                         LISTEN      22536/master
tcp        0      0 localhost.localdomain:10024 *:*                         LISTEN      11188/amavisd (ch13
tcp        0      0 localhost.localdomain:10025 *:*                         LISTEN      22536/master
tcp        0      0 *:smtp                      *:*                         LISTEN      22536/master
tcp        0      0 localhost:10024             *:*                         LISTEN      11188/amavisd (ch13

I commented out the following line in main.cf and everything started working properly.

Code:

#content_filter = amavis:[127.0.0.1]:10024

This is clearly a problem with amavisd but I don't know where to go from here.

 

You can set the amavis-loglevel to 2, restart amavis and check the amavis.log:

Code:

$DO_SYSLOG = 0;
$LOGFILE = "/var/log/amavis.log";  # (defaults to empty, no log)
# Set the log_level to 5 for debuggin$log_level = 2;  # (defaults to 0)

And you should also check the service amavis 127.0.0.1:10025 in the master.cf

 

Changing the loglevel results in an error.

Code:

Shutting down amavisd: Failed to open log file /var/log/amavis.log: Permission denied at /usr/sbin/amavisd line 2332.

 

I managed to get it logging to maillog. I used telnet to connect to port 10024 and got the amavis response so it is started and listening properly. I sent some random keystrokes and watched the errors (unknown command, as expected) in maillog. So logging is working as well, bit I'm not seeing any other amavis messages at all. Not when the service is started and not when mail hits the MTA.

 

Delivery still fails. The the original error I posted is shown without any additional information.

Code:

Apr 15 18:09:37 myhost postfix/error[21484]: 3AE813E04F5C: to=<[email protected]>, relay=none, delay=1264, delays=1264/0.05/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting)
a.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=4059, delays=4059/0.02/0.01/0, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting)
Apr 15 18:09:37 myhost postfix/smtp[21478]: 4D76E3E04F5E: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, delay=679, delays=678/0.03/0/0, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting)
Apr 15 18:09:37 myhost amavis[19611]: (!)DENIED ACCESS from IP 123.456.789.123, policy bank ''

 

I'll take a look in the backup and diff the files instead of just restoring them. Whatever changed must be what is stopping it.