Installed OK - Can send but not recieve email

[gregbazar]

Hi,

Great install script. I got the whole thing up and running in 20 minutes.

I am however having a couple of post installation issues.

Here is my setup:

Hostname: mail.bustedcamel.com
Mail Domain 1: bustedcamel.com
Mail Domain 2: ironfish.net

When I send mail to these addresses, they get bounced.

I can log into port 25 via telnet to send test messages, and the SMTP server accepts them OK. Here is a copy of the transaction:

220 mail.bustedcamel.com ESMTP Postfix
EHLO bustedcamel.com
250-mail.bustedcamel.com
250-PIPELINING
250-SIZE 51200000
250-VRFY
250-ETRN
250-STARTTLS
250 8BITMIME
MAIL FROM:tim-1@3d-p.com
250 Ok
RCPT TO:greg at bustedcamel com
DATA
250 Ok
354 End data with .
Subject:  Hello Greg
Test Message
.

QUIT
250 Ok: queued as 2B280E4C73B

The message never shows up to greg at bustedcamel com.

The zimbra log shows the message ID in the following context:

Nov  4 18:48:56 mail postfix/smtpd[1874]: connect from unknown[192.168.77.107]
Nov  4 18:48:58 mail postfix/smtpd[1874]: 2B280E4C73B: client=unknown[192.168.77.107]
Nov  4 18:48:58 mail postfix/cleanup[1006]: 2B280E4C73B: message-id=<20051105004858.2B280E4C73B@mail.bustedcamel.com>
Nov  4 18:48:58 mail postfix/qmgr[17877]: 2B280E4C73B: from=, size=387, nrcpt=1 (queue active)
Nov  4 18:48:58 mail postfix/smtpd[1874]: disconnect from unknown[192.168.77.107]
Nov  4 18:48:58 mail amavis[17419]: (17419-02) ESMTP::10024 /opt/zimbra/amavisd/tmp/amavis-20051104T175414-17419:  ->  Received: SIZE=387 from mail.bustedcamel.com ([127.0.0.1]) by localhost (mail.bustedcamel.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17419-02 for ; Fri,  4 Nov 2005 18:48:58 -0600 (CST)
Nov  4 18:48:58 mail amavis[17419]: (17419-02) body hash: bcfe53d9a81f2d0382a280d017796084
Nov  4 18:48:58 mail amavis[17419]: (17419-02) Checking: GwWk3Z7Fujv0 [192.168.77.107]  -> 
Nov  4 18:48:58 mail amavis[17419]: (17419-02) cached bcfe53d9a81f2d0382a280d017796084 from  (1,0)
Nov  4 18:48:58 mail amavis[17419]: (17419-02) p001 1 Content-Type: text/plain, size: 13 B, name: 
Nov  4 18:48:58 mail amavis[17419]: (17419-02) Checking for banned types and filenames
Nov  4 18:48:58 mail amavis[17419]: (17419-02) collect banned table[0]: greg @ bustedcamel com, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x910ea40)
Nov  4 18:48:58 mail amavis[17419]: (17419-02) p.path greg @ bustedcamel com: "P=p001,L=1,M=text/plain,T=asc"
Nov  4 18:48:58 mail amavis[17419]: (17419-02) spam_scan: hits=-3.935 tests=[ALL_TRUSTED=-3.3,BAYES_20=-1.951,NO_REAL_NAME=0.007,SUB_HELLO=0.007,UNDISC_RECIPS=1.302]
Nov  4 18:48:58 mail amavis[17419]: (17419-02) lookup_ldap_attr(amavisspamkilllevel) (WARN: no such attribute in LDAP entry), "greg @ bustedcamel com" result=undef
Nov  4 18:48:58 mail amavis[17419]: (17419-02) lookup_ldap_attr(amavisspamtaglevel) (WARN: no such attribute in LDAP entry), "greg @ bustedcamel com" result=undef
Nov  4 18:48:58 mail amavis[17419]: (17419-02) lookup_ldap_attr(amavisspamtag2level) (WARN: no such attribute in LDAP entry), "greg @ bustedcamel com" result=undef
Nov  4 18:48:58 mail amavis[17419]: (17419-02) SPAM-TAG,  -> , No, hits=-3.935 tagged_above=-10 required=6.6 autolearn=no tests=[ALL_TRUSTED=-3.3, BAYES_20=-1.951, NO_REAL_NAME=0.007, SUB_HELLO=0.007, UNDISC_RECIPS=1.302]
Nov  4 18:48:58 mail postfix/smtpd[4675]: connect from localhost.localdomain[127.0.0.1]
Nov  4 18:48:58 mail amavis[17419]: (17419-02) AUTH not needed, user='', MTA offers ''
Nov  4 18:48:58 mail postfix/smtpd[4675]: 5B67DE4C766: client=localhost.localdomain[127.0.0.1]
Nov  4 18:48:58 mail amavis[17419]: (17419-02) response to RCPT TO for : "250 Ok"
Nov  4 18:48:58 mail postfix/cleanup[1006]: 5B67DE4C766: message-id=<20051105004858.2B280E4C73B@mail bustedcamel com>
Nov  4 18:48:58 mail postfix/qmgr[17877]: 5B67DE4C766: from=, size=1043, nrcpt=1 (queue active)
Nov  4 18:48:58 mail postfix/smtpd[4675]: disconnect from localhost.localdomain[127.0.0.1]
Nov  4 18:48:58 mail amavis[17419]: (17419-02) FWD via SMTP:  -> , 250 2.6.0 Ok, id=17419-02, from MTA([127.0.0.1]:10025): 250 Ok: queued as 5B67DE4C766
Nov  4 18:48:58 mail amavis[17419]: (17419-02) lookup_ldap_attr(amavisspamtag2level) (WARN: no such attribute in LDAP entry), "greg @ bustedcamel com" result=undef
Nov  4 18:48:58 mail amavis[17419]: (17419-02) Passed CLEAN, LOCAL [192.168.77.107] [192.168.77.107]  -> , Message-ID: <20051105004858.2B280E4C73B@mail.bustedcamel.com>, mail_id: GwWk3Z7Fujv0, Hits: -3.935, 212 ms
Nov  4 18:48:58 mail amavis[17419]: (17419-02) TIMING [total 216 ms] - SMTP EHLO: 3 (2%)2, SMTP pre-MAIL: 1 (0%)2, lookup_ldap: 22 (10%)12, SMTP pre-DATA-flush: 2 (1%)13, SMTP DATA: 15 (7%)20, body_hash: 1 (1%)21, gen_mail_id: 1 (0%)21, mime_decode: 10 (4%)25, get-file-type1: 11 (5%)31, decompose_part: 1 (0%)31, parts_decode: 0 (0%)31, spam-wb-list: 7 (3%)34, SA msg read: 0 (0%)34, SA parse: 1 (0%)35, SA check: 54 (25%)60, update_cache: 2 (1%)61, deal_with_mail_size: 1 (0%)61, fwd-connect: 9 (4%)65, fwd-mail-from: 5 (2%)68, fwd-rcpt-to: 3 (1%)69, write-header: 2 (1%)70, fwd-data: 0 (0%)70, fwd-data-end: 45 (21%)91, fwd-rundown: 3 (1%)92, main_log_entry: 13 (6%)99, update_snmp: 1 (1%)99, unlink-1-files: 1 (1%)100, rundown: 0 (0%)100
Nov  4 18:48:58 mail postfix/smtp[4673]: 2B280E4C73B: to=, relay=127.0.0.1[127.0.0.1], delay=0, status=sent (250 2.6.0 Ok, id=17419-02, from MTA([127.0.0.1]:10025): 250 Ok: queued as 5B67DE4C766)
Nov  4 18:48:58 mail postfix/qmgr[17877]: 2B280E4C73B: removed
Nov  4 18:48:58 mail amavis[17419]: (17419-02) extra modules loaded: Net/LDAP/Bind.pm
Nov  4 18:48:58 mail amavis[17419]: (17419-02) load: 0 %, total idle 3283.267 s, busy 0.562 s
Nov  4 18:48:58 mail postfix/lmtp[4676]: 5B67DE4C766: to=, relay=none, delay=0, status=deferred (connect to bustedcamel.com[65.182.69.61]: Connection refused)

My mailbox is empty, but it says I am using 335 bytes of space... ?

I can ping mail.bustedcamel.com and bustedcamel.com from the command prompt.

Any help would be great.

Thanks.
G

[marcmac]

Note that the refusal is LMTP, not SMTP

mail postfix/lmtp[4676]: 5B67DE4C766: to=, relay=none, delay=0, status=deferred (connect to bustedcamel.com[65.182.69.61]: Connection refused)

Is 65.182.69.61 the address of the box, or is that the public IP of a router? I see the original connection was from 192.168.77.107, which makes me think there's some NAT going on.

Can you go from the mail server to the 65.182.69.61 address, port 7025? (not 25 - 7025). If not, make sure you open that up (just from this host).

(Also - is everything running? If tomcat's not up, that will break things, too. Firewall issues on the box could also break stuff)

[gregbazar]

By adding the SMTP and LMTP ports to my firewall rules it worked.

Thanks for the help. Now I have to go google and figure out what the heck LMTP is...

[marcmac]

Ask, and ye shall receive:
http://www.faqs.org/rfcs/rfc2033.html

(also, man -M /opt/zimbra/postfix/man lmtp)