Mailserver / Postfix Problems

[mority]

I have pretty much the same problem as oaky.

When I try to send a mail to to a user on a virtual mail domain on the mail server I am getting these error messages in /var/log/mail.log:

Jul 11 17:53:48 m34sxx postfix/smtpd[9920]: connect from mail.gmx.net[213.165.64.21]
Jul 11 17:53:48 m34sxx postfix/smtpd[9920]: 150843ECCF: client=mail.gmx.net[213.165.64.21]
Jul 11 17:53:48 m34sxx postfix/cleanup[9927]: 150843ECCF: message-id=<44B3E5C7.90208@gmx.net>
Jul 11 17:53:48 m34sxx postfix/qmgr[9746]: 150843ECCF: from=<mo2001@gmx.net>, size=791, nrcpt=1 (queue active)
Jul 11 17:53:48 m34sxx amavis[10048]: DENIED ACCESS from IP 83.151.xx.xx
Jul 11 17:53:48 m34sxx postfix/smtp[9747]: connect to 127.0.0.1[127.0.0.1]: server dropped connection without sending the initial SMTP greeting (port 10024)
Jul 11 17:53:48 m34sxx postfix/smtp[9747]: 150843ECCF: to=<mo@foobar.com>, relay=none, delay=0, status=deferred (connect to 127.0.0.1[127.0.0.1]: server dropped connection without sending the initial SMTP greeting)
Jul 11 17:53:48 m34sxx postfix/smtpd[9920]: disconnect from mail.gmx.net[213.165.64.21]

I would say the line I marked bold is the crucial one. 83.151.xx.xx is the public static IP address of my server running postfix. So there must be something wrong in the amavis config. But what can I do about it? Please let me know if I should post any config files.


I tried to "deactivate" amavis as oaky did like this

/etc/init.d/amavis stop

but then I get this in /var/log/mail.log:

Jul 11 18:03:48 m34sxx postfix/smtpd[12454]: connect from mail.gmx.net[213.165.64.21]
Jul 11 18:03:49 m34sxx postfix/smtpd[12454]: 064C23ECD0: client=mail.gmx.net[213.165.64.21]
Jul 11 18:03:49 m34sxx postfix/cleanup[12461]: 064C23ECD0: message-id=<44B3E820.4000109@gmx.net>
Jul 11 18:03:49 m34sxx postfix/qmgr[9746]: 064C23ECD0: from=<mo2001@gmx.net>, size=795, nrcpt=1 (queue active)
Jul 11 18:03:49 m34sxx postfix/smtp[12462]: connect to 127.0.0.1[127.0.0.1]: Connection refused (port 10024)
Jul 11 18:03:49 m34sxx postfix/smtpd[12454]: disconnect from mail.gmx.net[213.165.64.21]
Jul 11 18:03:49 m34sxx postfix/smtp[12462]: 064C23ECD0: to=<mo@foobar.com>, relay=none, delay=0, status=deferred (connect to 127.0.0.1[127.0.0.1]: Connection refused)

[falko]

What's in /etc/postfix/main.cf (please strip out the comments)?
What's the output of

netstat -tap

(when amavisd is running) and

iptables -L

?

[mority]

Here goes the /etc/postfix/main.cf

smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
biff = no

append_dot_mydomain = no

myhostname = m34sxx.foobar.com
alias_maps = hash:/etc/aliases
alias_database = hash:/etc/aliases
myorigin = /etc/mailname
mydestination = m34s10.foobar.com, localhost, localhost.localdomain
relayhost = 
mynetworks = 127.0.0.0/8
mailbox_size_limit = 0
recipient_delimiter = +
inet_interfaces = all
virtual_alias_domains = 
virtual_alias_maps = proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf, mysql:/etc/postfix/mysql-virtual_email2email.cf
virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql-virtual_domains.cf
virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf
virtual_mailbox_base = /home/vmail
virtual_uid_maps = static:5000
virtual_gid_maps = static:5000
smtpd_sasl_auth_enable = yes
broken_sasl_auth_clients = yes
smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination
smtpd_use_tls = yes
smtpd_tls_cert_file = /etc/postfix/smtpd.cert
smtpd_tls_key_file = /etc/postfix/smtpd.key
transport_maps = proxy:mysql:/etc/postfix/mysql-virtual_transports.cf
virtual_create_maildirsize = yes
virtual_mailbox_extended = yes
virtual_mailbox_limit_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailbox_limit_maps.cf
virtual_mailbox_limit_override = yes
virtual_maildir_limit_message = "The user you are trying to reach is over quota."
virtual_overquota_bounce = yes
proxy_read_maps = $local_recipient_maps $mydestination $virtual_alias_maps $virtual_alias_domains $virtual_mailbox_maps $virtual_mailbox_domains $relay_recipient_maps $relay_domains $canonical_maps $sender_canonical_maps $recipient_canonical_maps $relocated_maps $transport_maps $mynetworks $virtual_mailbox_limit_maps
content_filter = amavis:[127.0.0.1]:10024
receive_override_options = no_address_mappings

Here is the output of 'netstat -tap':

Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 m34sxx.foobar.com:imaps  *:*                     LISTEN     15619/couriertcpd
tcp        0      0 m34sxx.foobar.com:10024  *:*                     LISTEN     25831/amavisd (mast
tcp        0      0 m34sxx.foobar.com:10025  *:*                     LISTEN     9743/master
tcp        0      0 m34sxx.foobar.com:mysql  *:*                     LISTEN     17778/mysqld
tcp        0      0 m34sxx.foobar.com:imap2  *:*                     LISTEN     10257/couriertcpd
tcp        0      0 m34sxx.foobar.com:sunrpc *:*                     LISTEN     15132/portmap
tcp        0      0 m34sxx.foobar.com:www    *:*                     LISTEN     15818/apache2
tcp        0      0 m34sxx.foobar.com:ssh    *:*                     LISTEN     5203/sshd
tcp        0      0 m34sxx.foobar.com:984    *:*                     LISTEN     15224/famd
tcp        0      0 m34sxx.foobar.com:smtp   *:*                     LISTEN     9743/master
tcp        0      0 m34sxx.foobar.com:https  *:*                     LISTEN     15818/apache2
LISHED29994/sshd: mo [pri

iptables does not give me output because it's a virtual server where I am not allowed to use iptables.

[falko]

I found this on the internet: http://www.irbs.net/internet/postfix/0402/2378.html

[mority]

Thanks for the link, falko!

I changed the line

@inet_acl = qw( 127.0.0.1 );

to

@inet_acl = qw( 83.151.31.44 );

according to the information from the link. And this seems to me to have fixed amavis. But now I get many error messages about ClamAV failing to scan or something and the mail still does not get delivered

Here is the excerpt from /var/log/mail.log:

Jul 13 14:17:24 m34s10 postfix/smtpd[6441]: connect from mail.gmx.de[213.165.64.21]
Jul 13 14:17:24 m34s10 postfix/smtpd[6441]: A9F7E3ECD3: client=mail.gmx.de[213.165.64.21]
Jul 13 14:17:24 m34s10 postfix/cleanup[6446]: A9F7E3ECD3: message-id=<44B65614.3060804@gmx.net>
Jul 13 14:17:24 m34s10 postfix/qmgr[5816]: A9F7E3ECD3: from=<mo2001@gmx.net>, size=770, nrcpt=1 (queue active)
Jul 13 14:17:24 m34s10 postfix/smtpd[6441]: disconnect from mail.gmx.de[213.165.64.21]
Jul 13 14:17:24 m34s10 amavis[6333]: (06333-01) Clam Antivirus-clamd FAILED - unknown status: /var/lib/amavis/amavis-20060713T161724-06333/parts: lstat() failed. ERROR\n
Jul 13 14:17:24 m34s10 amavis[6333]: (06333-01) WARN: all primary virus scanners failed, considering backups
Jul 13 14:17:29 m34s10 dccproc[6454]: socket(UDP): Address family not supported by protocol
Jul 13 14:17:29 m34s10 postfix/smtpd[6455]: connect from localhost[127.0.0.1]
Jul 13 14:17:29 m34s10 postfix/smtpd[6455]: 6BE2D3ECD6: client=localhost[127.0.0.1]
Jul 13 14:17:29 m34s10 postfix/cleanup[6446]: 6BE2D3ECD6: message-id=<44B65614.3060804@gmx.net>
Jul 13 14:17:29 m34s10 postfix/qmgr[5816]: 6BE2D3ECD6: from=<mo2001@gmx.net>, size=1229, nrcpt=1 (queue active)
Jul 13 14:17:29 m34s10 postfix/smtpd[6455]: disconnect from localhost[127.0.0.1]
Jul 13 14:17:29 m34s10 amavis[6333]: (06333-01) Passed, <mo2001@gmx.net> -> <mo@eurosprachdienst.com>, Message-ID: <44B65614.3060804@gmx.net>, Hits: 1.177
Jul 13 14:17:29 m34s10 postfix/smtp[6447]: A9F7E3ECD3: to=<mo@eurosprachdienst.com>, relay=127.0.0.1[127.0.0.1], delay=5, status=sent (250 2.6.0 Ok, id=06333-01, from MTA: 250 Ok: queued as 6BE2D3ECD6)
Jul 13 14:17:29 m34s10 postfix/qmgr[5816]: A9F7E3ECD3: removed
Jul 13 14:17:43 m34s10 postfix/virtual[6487]: fatal: mysql:/etc/postfix/mysql-virtual_mailboxes.cf: proxy map is not allowed for security sensitive data
Jul 13 14:17:44 m34s10 postfix/master[5813]: warning: process /usr/lib/postfix/virtual pid 6487 exit status 1
Jul 13 14:17:44 m34s10 postfix/master[5813]: warning: /usr/lib/postfix/virtual: bad command startup -- throttling
Jul 13 14:18:44 m34s10 postfix/virtual[6592]: fatal: mysql:/etc/postfix/mysql-virtual_mailboxes.cf: proxy map is not allowed for security sensitive data
Jul 13 14:18:45 m34s10 postfix/master[5813]: warning: process /usr/lib/postfix/virtual pid 6592 exit status 1
Jul 13 14:18:45 m34s10 postfix/master[5813]: warning: /usr/lib/postfix/virtual: bad command startup -- throttling

[falko]

Originally Posted by mority

Jul 13 14:17:24 m34s10 amavis[6333]: (06333-01) Clam Antivirus-clamd FAILED - unknown status: /var/lib/amavis/amavis-20060713T161724-06333/parts: lstat() failed. ERROR\n

Please check the ClamAV part in amavisd.conf:

@av_scanners = (

### http://www.clamav.net/
['Clam Antivirus-clamd',
  \&ask_daemon, ["CONTSCAN {}\n", "/var/run/clamav/clamd.ctl"],
  qr/\bOK$/, qr/\bFOUND$/,
  qr/^.*?: (?!Infected Archive)(.*) FOUND$/ ],
# NOTE: run clamd under the same user as amavisd;  match the socket
# name (LocalSocket) in clamav.conf to the socket name in this entry
# When running chrooted one may prefer: ["CONTSCAN {}\n","$MYHOME/clamd"],

);

@av_scanners_backup = (

  ### http://www.clamav.net/
  ['Clam Antivirus - clamscan', 'clamscan',
    "--stdout --no-summary -r --tempdir=$TEMPBASE {}", [0], [1],
    qr/^.*?: (?!Infected Archive)(.*) FOUND$/ ],

);

Maybe also a reboot helps. If not, then this is probably because you have a vserver... But then the backup scanner should still work.

Originally Posted by mority

Jul 13 14:17:43 m34s10 postfix/virtual[6487]: fatal: mysql:/etc/postfix/mysql-virtual_mailboxes.cf: proxy map is not allowed for security sensitive data

Have a look here: http://www.howtoforge.com/forums/sho...52&postcount=4

[mority]

I deleted those "proxy:" strings according to your instructions from the link. Now I get the following in /var/log/mail.log (clamav is still failing in the first place but the backup scanner seems to work now) and the first email got delivered to my own little mail server. Hooray and great thanks to you, falko!

Jul 14 13:38:21 m34s10 postfix/smtpd[18976]: connect from mail.gmx.net[213.165.64.21]
Jul 14 13:38:22 m34s10 postfix/smtpd[18976]: 1C5BC3EAF5: client=mail.gmx.net[213.165.64.21]
Jul 14 13:38:22 m34s10 postfix/cleanup[18984]: 1C5BC3EAF5: message-id=<44B79E71.7090900@gmx.net>
Jul 14 13:38:22 m34s10 postfix/qmgr[17952]: 1C5BC3EAF5: from=<mo2001@gmx.net>, size=772, nrcpt=1 (queue active)
Jul 14 13:38:22 m34s10 postfix/smtpd[18976]: disconnect from mail.gmx.net[213.165.64.21]
Jul 14 13:38:29 m34s10 amavis[7420]: (07420-05) Clam Antivirus-clamd FAILED - unknown status: /var/lib/amavis/amavis-20060714T153826-07420/parts: lstat() failed. ERROR\n
Jul 14 13:38:29 m34s10 amavis[7420]: (07420-05) WARN: all primary virus scanners failed, considering backups
Jul 14 13:38:43 m34s10 dccproc[19018]: socket(UDP): Address family not supported by protocol
Jul 14 13:38:43 m34s10 postfix/smtpd[19019]: connect from localhost[127.0.0.1]
Jul 14 13:38:43 m34s10 postfix/smtpd[19019]: BF8013ECC8: client=localhost[127.0.0.1]
Jul 14 13:38:43 m34s10 postfix/cleanup[18984]: BF8013ECC8: message-id=<44B79E71.7090900@gmx.net>
Jul 14 13:38:43 m34s10 postfix/qmgr[17952]: BF8013ECC8: from=<mo2001@gmx.net>, size=1231, nrcpt=1 (queue active)
Jul 14 13:38:43 m34s10 postfix/smtpd[19019]: disconnect from localhost[127.0.0.1]
Jul 14 13:38:43 m34s10 postfix/virtual[19022]: BF8013ECC8: to=<mo@eurosprachdienst.com>, relay=virtual, delay=0, status=sent (delivered to maildir)
Jul 14 13:38:43 m34s10 postfix/qmgr[17952]: BF8013ECC8: removed
Jul 14 13:38:43 m34s10 amavis[7420]: (07420-05) Passed, <mo2001@gmx.net> -> <mo@eurosprachdienst.com>, Message-ID: <44B79E71.7090900@gmx.net>, Hits: 0.615
Jul 14 13:38:44 m34s10 postfix/smtp[18985]: 1C5BC3EAF5: to=<mo@eurosprachdienst.com>, relay=127.0.0.1[127.0.0.1], delay=22, status=sent (250 2.6.0 Ok, id=07420-05, from MTA: 250 Ok: queued as BF8013ECC8)
Jul 14 13:38:44 m34s10 postfix/qmgr[17952]: 1C5BC3EAF5: removed

[falko]

Looks ok (apart from the ClamAV error, but if your backup scanner works, it's ok).

[mority]

IMAP and receiving mails is working perfect now, but I still got a problem with sending mail. The authentication at the database does not seem to work here.
Here's a log entry I found in /var/log/auth.log:

Jul 16 12:54:19 m34s10 postfix/smtpd[8630]: sql_select option missing
Jul 16 12:54:19 m34s10 postfix/smtpd[8630]: auxpropfunc error no mechanism available
Jul 16 12:54:19 m34s10 postfix/smtpd[8630]: _sasl_plugin_load failed on sasl_auxprop_plug_init for plugin: sql
Jul 16 12:54:27 m34s10 saslauthd[5022]: pam_mysql: MySQL err Access denied for user 'mail_admin'@'localhost' (using password: YES)
Jul 16 12:54:27 m34s10 saslauthd[5022]: DEBUG: auth_pam: pam_authenticate failed: Authentication failure
Jul 16 12:54:27 m34s10 saslauthd[5022]: do_auth         : auth failure: [user=mo@agrav.org] [service=smtp] [realm=agrav.org] [mech=pam] [reason=PAM auth error]
Jul 16 12:54:28 m34s10 saslauthd[5024]: pam_mysql: MySQL err Access denied for user 'mail_admin'@'localhost' (using password: YES)
Jul 16 12:54:28 m34s10 saslauthd[5024]: DEBUG: auth_pam: pam_authenticate failed: Authentication failure
Jul 16 12:54:28 m34s10 saslauthd[5024]: do_auth         : auth failure: [user=mo@agrav.org] [service=smtp] [realm=agrav.org] [mech=pam] [reason=PAM auth error]

I double checked the content of /etc/pam.d/smtp. It is definitely the right database user and password in there. I also tried to put the password in double quotes since I use special characters in it but I keep getting thos Authentication error messages for MySQL in auth.log. Do you have any idea to this issue, too?

[falko]

Does /etc/pam.d/smtp look like this?

auth    required   pam_mysql.so user=mail_admin passwd=mail_admin_password host=127.0.0.1 db=mail table=users usercolumn=email passwdcolumn=password crypt=1
account sufficient pam_mysql.so user=mail_admin passwd=mail_admin_password host=127.0.0.1 db=mail table=users usercolumn=email passwdcolumn=password crypt=1

Please use a password without special characters for now.