Member
Registered: Jul 2004
Location: Zinzinnati, OH
Distribution: RH, FC 1-6, F 7-21, Debian, LinuxPPC, Knoppix, Ubuntu, Yellow Dog
Posts: 176
Rep:
|
Postfix cannot send email from Thunderbird/Squirrelmail to recipient behind firewall
Hello All,
My company email server has been working flawlessly for the last 5+ years. Recently, one of our clients put their email server behind a firewall (an assumption on my part; details below). Ever since, email sent from within the company (192.168.xxx.xxx internal address; all computers and server is behind a NAT firewall [Netgear FVX538]) is either being sent to the client after some delay (if email is sent using Outlook) or is being deferred until the messages expire (Thunderbird, Squirrelmail, etc.). Email sent to the client from anywhere outside the company (using Thunderbird, Outlook or any other email client) is also delivered without any problems (usually after a short delay). All other emails to the World are being sent without any problems at all (both inside and outside the company; using any email client or webmail). I did contact the client's postmaster, but the client, being a large government agency, will probably not address the problem (if it is on their side) anytime soon. I am not sure if I can do anything from my end to solve the problem. Ever since the problem with the client began, I added two statements to the postfix configuration file (smtp_pix_workaround_delay_time = 20s and smtp_pix_workaround_threshold_time = 0s); this seemed to help things a bit - it reduced the delay for emails sent via Outlook to a few minutes (as opposed to 30+ minutes); emails sent using Thunderbird/webmail are still being deferred.
Server details:
Dual quad-core processor machine, 32 GB RAM, dual 1 gbps network, running Fedora 14 (64-bit; loosely modeled along the lines of Perfect Server (with ISPConfig2) as described on the howtoforge website). Running Postfix (v. 2.7.1), Dovecot (v. 2.0.9).
Postfix details:
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
body_checks = regexp:/etc/postfix/mbl-body-deny
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/libexec/postfix
data_directory = /var/lib/postfix
debug_peer_level = 2
default_destination_concurrency_limit = 100
disable_vrfy_command = yes
home_mailbox = Maildir/
html_directory = no
inet_interfaces = all
mail_owner = postfix
mailbox_command =
mailbox_size_limit = 0
mailq_path = /usr/bin/mailq.postfix
manpage_directory = /usr/share/man
message_size_limit = 1000000000
mydestination = /etc/postfix/local-host-names
myhostname = smtp.ptsied.com
mynetworks = 127.0.0.0/8
myorigin = $mydomain
newaliases_path = /usr/bin/newaliases.postfix
queue_directory = /var/spool/postfix
readme_directory = /usr/share/doc/postfix-2.7.1/README_FILES
sample_directory = /usr/share/doc/postfix-2.7.1/samples
sendmail_path = /usr/sbin/sendmail.postfix
setgid_group = postdrop
smtp_pix_workaround_delay_time = 20s
smtp_pix_workaround_threshold_time = 0s
smtp_tls_CAfile = /etc/postfix/ssl/cacert.crt
smtp_tls_cert_file = /etc/postfix/ssl/smtpd.crt
smtp_tls_key_file = /etc/postfix/ssl/private.key
smtp_tls_note_starttls_offer = yes
smtp_use_tls = yes
smtpd_data_restrictions = reject_unauth_pipelining, permit
smtpd_delay_reject = yes
smtpd_helo_restrictions = permit_mynetworks, permit_sasl_authenticated, check_helo_access hash:/etc/postfix/access_helo, reject_unauth_pipelining, reject_non_fqdn_hostname, reject_non_fqdn_helo_hostname, reject_invalid_helo_hostname, reject_unknown_helo_hostname, permit
smtpd_recipient_restrictions = reject_unauth_pipelining, reject_invalid_hostname, permit_sasl_authenticated, reject_unauth_destination, reject_non_fqdn_hostname, reject_non_fqdn_sender, reject_non_fqdn_recipient, reject_unknown_sender_domain, reject_unknown_recipient_domain, permit_mynetworks, reject_unauth_destination, reject_unlisted_recipient, reject_rbl_client zen.spamhaus.org, reject_rbl_client b.barracudacentral.org, check_policy_service inet:127.0.0.1:60000, permit
smtpd_reject_unlisted_sender = yes
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
smtpd_sasl_local_domain =
smtpd_sasl_security_options = noanonymous
smtpd_sender_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_non_fqdn_sender, reject_unknown_sender_domain, reject_unknown_address, check_sender_access hash:/etc/postfix/sender_restrictions, reject_rbl_client zen.spamhaus.org, reject_rbl_client b.barracudacentral.org, permit
smtpd_tls_CAfile = /etc/postfix/ssl/cacert.crt
smtpd_tls_auth_only = no
smtpd_tls_cert_file = /etc/postfix/ssl/smtpd.crt
smtpd_tls_key_file = /etc/postfix/ssl/private.key
smtpd_tls_loglevel = 1
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
smtpd_use_tls = yes
tls_random_source = dev:/dev/urandom
transport_maps = hash:/etc/postfix/transport
unknown_local_recipient_reject_code = 550
virtual_mailbox_limit = 0
Server logs from prior to the problem:
Mail sent using Squirrelmail:
Mar 11 09:36:48 server postfix/smtpd[4969]: connect from server.xxx.xxx[192.168.xxx.xxx]
Mar 11 09:36:48 server postfix/smtpd[4969]: 5873B5850: client=server.xxx.xxx[192.168.xxx.xxx], sasl_method=LOGIN, sasl_username=xxx
Mar 11 09:36:48 server postfix/cleanup[5112]: 5873B5850: message-id=<13500831b10119d975a25c8270675b52.squirrel@www.xxx.xxx>
Mar 11 09:36:49 server postfix/qmgr[4145]: 5873B5850: from=<xxx@xxx.xxx>, size=94903, nrcpt=1 (queue active)
Mar 11 09:36:49 server postfix/smtpd[4969]: disconnect from server.xxx.xxx[192.168.xxx.xxx]
Mar 11 09:36:51 server postfix/smtpd[5132]: connect from unknown[127.0.0.1]
Mar 11 09:36:51 server postfix/smtpd[5132]: E26F855AA: client=unknown[127.0.0.1]
Mar 11 09:36:51 server postfix/cleanup[5112]: E26F855AA: message-id=<13500831b10119d975a25c8270675b52.squirrel@www.xxx.xxx>
Mar 11 09:36:52 server postfix/qmgr[4145]: E26F855AA: from=<xxx@xxx.xxx>, size=95760, nrcpt=1 (queue active)
Mar 11 09:36:52 server postfix/smtpd[5132]: disconnect from unknown[127.0.0.1]
Mar 11 09:36:52 server amavis[29986]: (29986-07) Passed CLEAN, MYNETS LOCAL [192.168.xxx.xxx] [xxx.xxx.xxx.xxx] <xxx@xxx.xxx> -> <yyy@yyy.yyy>, Message-ID: <13500831b10119d975a25c8270675b52.squirrel@www.xxx.xxx>, mail_id: w+BXmBOXYBvj, Hits: -3.156, size: 94903, queued_as: E26F855AA, 2264 ms
Mar 11 09:36:52 server postfix/smtp[5113]: 5873B5850: to=<yyy@yyy.yyy>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.7, delays=1.5/0/0/2.3, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=29986-07, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as E26F855AA)
Mar 11 09:36:52 server postfix/qmgr[4145]: 5873B5850: removed
Mar 11 09:36:54 server postfix/smtp[5228]: E26F855AA: to=<yyy@yyy.yyy>, relay=ms.yyy.yyy[zzz.zzz.zzz.zzz]:25, delay=2.4, delays=0.17/0.02/0.4/1.8, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as A9DEE5D4022)
Mar 11 09:36:55 server postfix/qmgr[4145]: E26F855AA: removed
Mail sent using Outlook:
Mar 11 11:25:45 server postfix/smtpd[8659]: connect from unknown [192.168.xxx.xxx]
Mar 11 11:25:45 server postfix/smtpd[8659]: 9CD194029: client=unknown [192.168.xxx.xxx], sasl_method=LOGIN, sasl_username=xxx
Mar 11 11:25:45 server postfix/cleanup[8662]: 9CD194029: message-id=<00bf01cbe009$67ab05e0$370111a0$@xxx.xxx>
Mar 11 11:25:45 server postfix/qmgr[4145]: 9CD194029: from=<xxx@xxx.xxx>, size=7835, nrcpt=1 (queue active)
Mar 11 11:25:48 server postfix/smtpd[8659]: disconnect from unknown [192.168.xxx.xxx]
Mar 11 11:25:49 server postfix/smtpd[8670]: connect from unknown [127.0.0.1]
Mar 11 11:25:49 server postfix/smtpd[8670]: 0B64A95E6: client=unknown [127.0.0.1]
Mar 11 11:25:49 server postfix/cleanup[8662]: 0B64A95E6:message-id=<00bf01cbe009$67ab05e0$370111a0$@xxx.xxx>
Mar 11 11:25:49 server postfix/qmgr[4145]: 0B64A95E6:from=<xxx@xxx.xxx>, size=8734, nrcpt=1 (queue active)
Mar 11 11:25:49 server postfix/smtpd[8670]: disconnect from unknown[127.0.0.1]
Mar 11 11:25:49 server amavis[29983]: (29983-14) Passed CLEAN, MYNETS LOCAL [192.168.xxx.xxx] [192.168.xxx.xxx] <xxx@xxx.xxx> -> <yyy@.yyy.yyy> Message-ID: <00bf01cbe009$67ab05e0$370111a0$@xxx.xxx>, mail_id:ybK8Z+RgGNTp, Hits: -3.009, size: 7835, queued_as: 0B64A95E6, 3177 ms
Mar 11 11:25:49 server postfix/smtp[8663]: 9CD194029: to=<yyy@yyy.yyy>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.5, delays=0.27/0/0/3.2, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=29983-14, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 0B64A95E6)
Mar 11 11:25:49 server postfix/qmgr[4145]: 9CD194029: removed
Mar 11 11:25:51 server postfix/smtp[8691]: 0B64A95E6: to=<yyy@yyy.yyy>, relay=ms.yyy.yyy [zzz.zzz.zzz.zzz]:25, delay=2.1, delays=0.04/0.02/1.3/0.72, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 859305D400A)
Mar 11 11:25:51 server postfix/qmgr[4145]: 0B64A95E6: removed
Server logs after the problem started (around March 13):
Mail sent using Squirrelmail (emails are deferred until they expire; other non-Outlook email clients have the same problem):
Mar 14 09:22:59 server postfix/smtpd[28336]: connect from server.xxx.xxx[192.168.xxx.xxx]
Mar 14 09:22:59 server postfix/smtpd[28336]: 186EE519D: client=server.xxx.xxx[192.168.xxx.xxx], sasl_method=LOGIN, sasl_username=xxx
Mar 14 09:22:59 server postfix/cleanup[28361]: 186EE519D: message-id=<bfa17edb3ec3ad33f7fc0c0d02c36fa9.squirrel@www.xxx.xxx>
Mar 14 09:22:59 server postfix/qmgr[26669]: 186EE519D: from=<xxx@xxx.xxx>, size=1646, nrcpt=1 (queue active)
Mar 14 09:22:59 server postfix/smtpd[28336]: disconnect from server.xxx.xxx[192.168.xxx.xxx]
Mar 14 09:23:01 server postfix/smtpd[28375]: connect from unknown [127.0.0.1]
Mar 14 09:23:01 server postfix/smtpd[28375]: 8E23151B1: client=unknown[127.0.0.1]
Mar 14 09:23:01 server postfix/cleanup[28361]: 8E23151B1: message-id=<bfa17edb3ec3ad33f7fc0c0d02c36fa9.squirrel@www.xxx.xxx>
Mar 14 09:23:01 server postfix/qmgr[26669]: 8E23151B1: from=<xxx@xxx.xxx>, size=2607, nrcpt=1 (queue active)
Mar 14 09:23:01 server postfix/smtpd[28375]: disconnect from unknown [127.0.0.1]
Mar 14 09:23:01 server amavis[25370]: (25370-05) Passed CLEAN, MYNETS LOCAL [192.168.xxx.xxx] [xxx.xxx.xxx.xxx] <xxx@xxx.xxx> -> <yyy@yyy.yyy>, Message-ID: <bfa17edb3ec3ad33f7fc0c0d02c36fa9.squirrel@www.xxx.xxx>, mail_id: ryZkTwKaOzqm, Hits: -3.176, size: 1646, queued_as: 8E23151B1, 2346 ms
Mar 14 09:23:01 server postfix/smtp[28362]: 186EE519D: to=<yyy@yyy.yyy>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.6, delays=0.26/0.02/0/2.3, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=25370-05, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 8E23151B1)
Mar 14 09:23:01 server postfix/qmgr[26669]: 186EE519D: removed
Mar 14 09:23:01 server postfix/smtp[28376]: 8E23151B1: enabling PIX workarounds: disable_esmtp delay_dotcrlf for ms.yyy.yyy [zzz.zzz.zzz.zzz]:25
Mar 14 09:33:02 server postfix/smtp[28376]: 8E23151B1: conversation with ms.yyy.yyy [zzz.zzz.zzz.zzz] timed out while sending end of data -- message may be sent more than once
Mar 14 09:33:02 server postfix/smtp[28376]: 8E23151B1: enabling PIX workarounds: disable_esmtp delay_dotcrlf for ms.yyy.yyy [zzz.zzz.zzz.zzz]:25
Mar 14 09:43:12 server postfix/smtp[28376]: 8E23151B1: to=<yyy@yyy.yyy>, relay=ms.yyy.yyy [zzz.zzz.zzz.zzz]:25, delay=1211, delays=0.09/0.02/601/610, dsn=4.4.2, status=deferred (conversation with ms.yyy.yyy [zzz.zzz.zzz.zzz] timed out while sending end of data -- message may be sent more than once)
.
.
.
Mar 16 19:39:13 server postfix/smtp[6795]: 8E23151B1: conversation with ms.yyy.yyy [zzz.zzz.zzz.zzz] timed out while sending end of data -- message may be sent more than once
Mar 16 19:39:13 server postfix/smtp[6795]: 8E23151B1: enabling PIX workarounds: disable_esmtp delay_dotcrlf for ms.yyy.yyy [zzz.zzz.zzz.zzz]:25
.
.
.
Mar 19 10:29:02 server postfix/qmgr[13563]: 8E23151B1: from=<xxx@xxx.xxx>, size=2607, nrcpt=1 (queue active)
Mar 19 10:49:23 server postfix/error[23404]: 8E23151B1: to=<yyy@yyy.yyy>, relay=none, delay=437182, delays=435961/1221/0/0.05, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with ms.yyy.yyy [zzz.zzz.zzz.zzz] timed out while sending end of data -- message may be sent more than once)
Mar 19 10:49:23 server postfix/qmgr[13563]: 8E23151B1: from=<xxx@xxx.xxx>, status=expired, returned to sender
Mar 19 10:49:23 server postfix/bounce[23409]: 8E23151B1: sender non-delivery notification: 72F5F1E4F2
Mar 19 10:49:23 server postfix/qmgr[13563]: 72F5F1E4F2: from=<>, size=4774, nrcpt=1 (queue active)
Mar 19 10:49:23 server postfix/qmgr[13563]: 8E23151B1: removed
Mar 19 10:49:23 server postfix/local[23414]: 72F5F1E4F2: to=<xxx@xxx.xxx>, relay=local, delay=0.09, delays=0.07/0.01/0/0.01, dsn=2.0.0, status=sent (delivered to maildir)
Mar 19 10:49:23 server postfix/qmgr[13563]: 72F5F1E4F2: removed
Mail sent using Outlook (some delay, but emails get delivered to the client within one hour):
Mar 16 17:39:10 server postfix/smtpd[3480]: connect from unknown[192.168.xxx.xxx]
Mar 16 17:39:10 server postfix/smtpd[3480]: 28B041EA07: client=unknown[192.168.xxx.xxx], sasl_method=LOGIN, sasl_username=xxx
Mar 16 17:39:10 server postfix/cleanup[3483]: 28B041EA07: message-id=<016801cbe423$05119de0$0f34d9a0$@xxx.xxx>
Mar 16 17:39:10 server postfix/qmgr[18738]: 28B041EA07: from=<xxx@xxx.xxx>, size=10956, nrcpt=1 (queue active)
Mar 16 17:39:13 server postfix/smtpd[3480]: disconnect from unknown[192.168.xxx.xxx]
Mar 16 17:39:13 server postfix/smtpd[3489]: connect from unknown[127.0.0.1]
Mar 16 17:39:13 server postfix/smtpd[3489]: 40E291EB5C: client=unknown[127.0.0.1]
Mar 16 17:39:13 server postfix/cleanup[3483]: 40E291EB5C: message-id=<016801cbe423$05119de0$0f34d9a0$@xxx.xxx>
Mar 16 17:39:13 server postfix/qmgr[18738]: 40E291EB5C: from=<xxx@xxx.xxx>, size=11856, nrcpt=1 (queue active)
Mar 16 17:39:13 server postfix/smtpd[3489]: disconnect from unknown[127.0.0.1]
Mar 16 17:39:13 server amavis[30858]: (30858-06) Passed CLEAN, MYNETS LOCAL [192.168.xxx.xxx] [192.168.xxx.xxx] <xxx@xxx.xxx> -> <yyy@yyy.yyy>, Message-ID: <016801cbe423$05119de0$0f34d9a0$@xxx.xxx>, mail_id: Mv-LGMt7h-Nr, Hits: -4.051, size: 10956, queued_as: 40E291EB5C, 2606 ms
Mar 16 17:39:13 server postfix/smtp[3484]: 28B041EA07: to=<yyy@yyy.yyy>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.2, delays=0.61/0.02/0/2.6, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=30858-06, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 40E291EB5C)
Mar 16 17:39:13 server postfix/qmgr[18738]: 28B041EA07: removed
Mar 16 17:39:13 server postfix/error[3492]: 40E291EB5C: to=<yyy@yyy.yyy>, relay=none, delay=0.13, delays=0.08/0.01/0/0.04, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with ms.yyy.yyy [zzz.zzz.zzz.zzz] timed out while sending end of data -- message may be sent more than once)
Mar 16 17:49:02 server postfix/qmgr[18738]: 40E291EB5C: from=<xxx@xxx.xxx>, size=11856, nrcpt=1 (queue active)
Mar 16 17:49:02 server postfix/smtp[3766]: 40E291EB5C: enabling PIX workarounds: disable_esmtp delay_dotcrlf for ms.yyy.yyy [zzz.zzz.zzz.zzz]:25
Mar 16 17:49:13 server postfix/smtp[3766]: 40E291EB5C: to=<yyy@yyy.yyy>, relay=ms.yyy.yyy [zzz.zzz.zzz.zzz]:25, delay=600, delays=589/0.03/0.39/11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as CB0D0444A8)
Mar 16 17:49:13 server postfix/qmgr[18738]: 40E291EB5C: removed
As you can see, the main difference between before and after is that postfix is enabling PIX workarounds, which leads me to believe that the client put their email servers behind a Cisco firewall. When I telnet the client server, I get this:
telnet yyy.yyy.yyy.yyy 25
Trying yyy.yyy.yyy.yyy...
Connected to ms.yyy.yyy (zzz.zzz.zzz.zzz).
Escape character is '^]'.
220 **********************************
ehlo yyy.yyy
250-ms.yyy.yyy
250-PIPELINING
250-SIZE 71680000
250-ETRN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
quit
221 2.0.0 Bye
Connection closed by foreign host.
I emailed the client's postmaster suggesting they disable smtp fixup. But still, what bothers me now is that Outlook works (both within and outside the company) while Thunderbird, webmail, etc. (used by ~90% of the users) do not. In addition, all email clients from outside the company can send email (authenticated via the company server) to the client without any problems. Is there anything I can do on my end to make non-Outlook clients work within the company (webmail is hosted on the company server; so, it would have an internal address as well)? Any help would be much appreciated.
Thanks,
cincindie
|