Duplicate mails in mailq / always_bcc

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

Duplicate mails in mailq / always_bcc

Niclas Rautenhaus
 

Hi list,

 

I am experiencing an issue with my postfix setup.

 

The desired results:

We use an appliance that archives all mails (incoming and outgoing) - due to laws that have been enforced here in Germany.

The documentation of the appliance states, that the main.cf should be updated with the following lines, which has been done

[hidden email]

 

In addition to that, in the transport_maps the IP and domain name of the appliance needs to be listed, which – again - has been done

bcc-domain.local    smtp:[192.168.N.NN]:1025

 

So far, so good. The transport_maps file was rehashed multiple times, and postfix got its restart.

But since I integrated the appliance into the postfix configuration, I get the symptoms as described below

 

The symptoms:

I am not yet sure whether all incoming mails are affected or not, but at least sometimes I get the following entry in my mailq (and respecively the mail.log):

 

5086760443    35318 Mon Nov 13 16:04:20  [hidden email]

(lost connection with 192.168.N.NN[192.168.N.NN] while sending end of data -- message may be sent more than once)

                                         [hidden email]

                                                                                                                     

Additionally, some mails are put twice in the queue, again I am not 100% sure whether all mails are affected by this or not:

7344360456    21858 Mon Nov 13 15:39:39  [hidden email]

(lost connection with 192.168.N.NN[192.168.N.NN] while sending end of data -- message may be sent more than once)

                                         [hidden email]

                                         [hidden email]

 

The configuration:

There are three filters I work with: spamassassin, clamav, KLMS

 

I already found out - thanks to postings on this mail list -  that when using "amavis" there are sometimes problems with the always_bcc attribute as well, but implementing the no_address_mappings did not resolve the issues.

 

Here are excerpts from my main.cf and master.cf

Output of "postconf -n"

alias_database = hash:/etc/aliases

alias_maps = hash:/etc/aliases

always_bcc = [hidden email]

command_directory = /usr/sbin

config_directory = /etc/postfix

content_filter = klms_postfix-afterqueue:127.0.0.1:10025

daemon_directory = /usr/lib/postfix

data_directory = /var/lib/postfix

debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5

default_privs = nobody

html_directory = /usr/share/doc/postfix/html

inet_interfaces = $myhostname, localhost

inet_protocols = ipv4

local_recipient_maps = unix:passwd.byname $alias_maps

mail_owner = postfix

mailbox_size_limit = 152428800

mailbox_transport = cyrus

mailq_path = /usr/bin/mailq

manpage_directory = /usr/share/man

message_size_limit = 152428800

mydestination = $myhostname, localhost.$mydomain, localhost

mydomain = domain.tld

myhostname = mail.domain.tld

mynetworks = 127.0.0.0/8 192.168.0.0/16 YY.YYY.YY.YYY/32 BB.BBB.BB.BBB/32

myorigin = $mydomain

newaliases_path = /usr/sbin/newaliases

queue_directory = /var/spool/postfix

readme_directory = /usr/share/doc/postfix

receive_override_options = no_address_mappings

relay_domains = $mydestination

relayhost = smtp.externalhoster.tld

sample_directory = /usr/share/doc/postifx/examples

sender_canonical_maps = hash:/etc/postfix/sender_canonical

sendmail_path = /usr/sbin/sendmail

setgid_group = postdrop

smtp_sasl_auth_enable = yes

smtp_sasl_password_maps = hash:/etc/postfix/sasl_auth

smtp_sasl_security_options = noanonymous

smtp_tls_mandatory_protocols = !SSLv2 !SSLv3

smtp_tls_protocols = !SSLv2, !SSLv3

smtp_tls_security_level = may

smtpd_banner = $myhostname ESMTP $mail_name

smtpd_tls_mandatory_protocols = !SSLv2 !SSLv3

smtpd_tls_protocols = !SSLv2 !SSLv3

transport_maps = hash:/etc/postfix/transport_maps

unknown_local_recipient_reject_code = 550

 

In the main.cf this entry "content_filter = klms_postfix-afterqueue:127.0.0.1:10025" is needed for the KLMS filter

 

master.cf:

The excerpts displaying the three filters:

# spamassassin

spamassassin unix -     n       n       -       -       pipe

        user=debian-spamd argv=/usr/bin/spamc -f -e /usr/sbin/sendmail -oi -f ${sender} ${recipient}

 

# AV scan filter (used by content_filter)

scan      unix  -       -       n       -       16      smtp

        -o smtp_send_xforward_command=yes

        -o smtp_enforce_tls=no

 

#klms-begin-afterqueue-filter

klms_postfix-afterqueue unix    -       -       n        -      10      smtp

        -o smtp_send_xforward_command=yes

127.0.0.1:10026 inet    n       -       n       -       10      smtpd

        -o content_filter=

        -o content_filter=scan:[127.0.0.1]:10027

        -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks

        -o smtpd_helo_restrictions=

        -o smtpd_client_restrictions=

        -o smtpd_sender_restrictions=

        -o smtpd_recipient_restrictions=permit_mynetworks,reject

        -o mynetworks=127.0.0.0/8,[::1]/128

        -o smtpd_authorized_xforward_hosts=127.0.0.0/8,[::1]/128

#klms-end-afterqueue-filter

 

# For injecting mail back into postfix from the filter

127.0.0.1:10028 inet  n -       n       -       16      smtpd

        -o content_filter=

        -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks,no_address_mappings

        -o smtpd_helo_restrictions=

        -o smtpd_client_restrictions=

        -o smtpd_sender_restrictions=

        -o smtpd_recipient_restrictions=permit_mynetworks,reject

        -o mynetworks_style=host

        -o smtpd_authorized_xforward_hosts=127.0.0.0/8

                       

Note that I did not change the master.cf and main.cf back to it's default values speaking of the "no_address_mappings" directive.

I carefully implemented that directive at any place that seemed logical to me, to no avail.

 

Debugging the issue by making the smtpd -v and -vv generated more output that was logged, however it did not help me understand where the issue comes from.

 

Could anybody shed some light on this issue?

Any help is appreciated, if more logfiles / information is needed, just ask.

 

Regards,

Niclas

 

Reply | Threaded
Open this post in threaded view
|

Re: Duplicate mails in mailq / always_bcc

Bill Cole-3
On 23 Nov 2017, at 5:28 (-0500), Niclas Rautenhaus wrote:

> The symptoms:
> I am not yet sure whether all incoming mails are affected or not, but
> at least sometimes I get the following entry in my mailq (and
> respecively the mail.log):
> 5086760443    35318 Mon Nov 13 16:04:20  [hidden email]
> (lost connection with 192.168.N.NN[192.168.N.NN] while sending end of
> data -- message may be sent more than once)
>                                          [hidden email]

The most likely cause is that your appliance or the network between it
and Postfix is behaving badly. Postfix sent the '<CRLF>.<CRLF>' that
signals the end of message data, but instead of getting a '250' reply
from the appliance and then either sending a QUIT command to initiate
the shutdown of the connection or a RSET command and sending another
queued message, the connection is closed. The fact that the problem is
happening so late in the process of sending a message eliminates Postfix
configuration as a critical cause.

The next steps for troubleshooting this would be:

1. Find ALL of the log lines related to one message that is stuck.

2. If there's a long delay between when Postfix connects to the
appliance and the failure, the likely proximate cause of the failure is
that the appliance is not detecting the end-of-data signal, and
eventually just drops the connection due to a timeout. This can happen
for a few different reasons, all involving how the message data and the
end-of-data signal are packaged in IP packets. Sometimes this is a
problem on the receiving end, with software which can't recognize the
end-of-data signal if it is split between two packets. Sometimes it is a
Path MTU issue, where something between the sender and receiver can't
handle a too-large packet but also can't get ICMP NEED-FRAG messages
back to the sender. To differentiate between those issues, you probable
need a network capture (using something like tcpdump or wireshark) of a
session that fails. However, if it is simply a Path MTU issue, you may
be able to reduce the MTU on the Postfix server (e.g. from the usual
1500 down to 1460 or even 1400) and make the problem entirely vanish. If
it is a problem with how the appliance handles an end-of-data signal
split between packets, try to get a refund for the device: it's junk.

3. If the failure is fast (<10s) then the problem could be an unwise
(and SMTP non-compliant) optimization of session closure by the
appliance that the Postfix server sees as a simple dropped connection.
Here again, a network capture of a session that fails would help
identify the problem (such as a final packet with the 250 reply to the
end-of-data signal and with the FIN flag set.)


--
Bill Cole
[hidden email] or [hidden email]
(AKA @grumpybozo and many *@billmail.scconsult.com addresses)
Currently Seeking Steady Work: https://linkedin.com/in/billcole
GP
Reply | Threaded
Open this post in threaded view
|

Re: Duplicate mails in mailq / always_bcc

GP
In reply to this post by Niclas Rautenhaus
On 11/23/2017 12:28 PM, Niclas Rautenhaus wrote:
 

Hi list,

 

I am experiencing an issue with my postfix setup.

 

The desired results:

We use an appliance that archives all mails (incoming and outgoing) - due to laws that have been enforced here in Germany.

The documentation of the appliance states, that the main.cf should be updated with the following lines, which has been done

[hidden email]

 

In addition to that, in the transport_maps the IP and domain name of the appliance needs to be listed, which – again - has been done

bcc-domain.local    smtp:[192.168.N.NN]:1025

 

So far, so good. The transport_maps file was rehashed multiple times, and postfix got its restart.

But since I integrated the appliance into the postfix configuration, I get the symptoms as described below

 

The symptoms:

I am not yet sure whether all incoming mails are affected or not, but at least sometimes I get the following entry in my mailq (and respecively the mail.log):

 

5086760443    35318 Mon Nov 13 16:04:20  [hidden email]

(lost connection with 192.168.N.NN[192.168.N.NN] while sending end of data -- message may be sent more than once)

                                         [hidden email]

                                                      


I had some similar symptom on a mail host  with multiple uplink provider setup . The problem went away by reducing the mtu on the default interface by a litle. I don't know if that will apply to your situation though....


                                                              

Additionally, some mails are put twice in the queue, again I am not 100% sure whether all mails are affected by this or not:

7344360456    21858 Mon Nov 13 15:39:39  [hidden email]

(lost connection with 192.168.N.NN[192.168.N.NN] while sending end of data -- message may be sent more than once)

                                         [hidden email]

                                         [hidden email]

 

The configuration:

There are three filters I work with: spamassassin, clamav, KLMS

 

I already found out - thanks to postings on this mail list -  that when using "amavis" there are sometimes problems with the always_bcc attribute as well, but implementing the no_address_mappings did not resolve the issues.

 

Here are excerpts from my main.cf and master.cf

Output of "postconf -n"

alias_database = hash:/etc/aliases

alias_maps = hash:/etc/aliases

always_bcc = [hidden email]

command_directory = /usr/sbin

config_directory = /etc/postfix

content_filter = klms_postfix-afterqueue:127.0.0.1:10025

daemon_directory = /usr/lib/postfix

data_directory = /var/lib/postfix

debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5

default_privs = nobody

html_directory = /usr/share/doc/postfix/html

inet_interfaces = $myhostname, localhost

inet_protocols = ipv4

local_recipient_maps = unix:passwd.byname $alias_maps

mail_owner = postfix

mailbox_size_limit = 152428800

mailbox_transport = cyrus

mailq_path = /usr/bin/mailq

manpage_directory = /usr/share/man

message_size_limit = 152428800

mydestination = $myhostname, localhost.$mydomain, localhost

mydomain = domain.tld

myhostname = mail.domain.tld

mynetworks = 127.0.0.0/8 192.168.0.0/16 YY.YYY.YY.YYY/32 BB.BBB.BB.BBB/32

myorigin = $mydomain

newaliases_path = /usr/sbin/newaliases

queue_directory = /var/spool/postfix

readme_directory = /usr/share/doc/postfix

receive_override_options = no_address_mappings

relay_domains = $mydestination

relayhost = smtp.externalhoster.tld

sample_directory = /usr/share/doc/postifx/examples

sender_canonical_maps = hash:/etc/postfix/sender_canonical

sendmail_path = /usr/sbin/sendmail

setgid_group = postdrop

smtp_sasl_auth_enable = yes

smtp_sasl_password_maps = hash:/etc/postfix/sasl_auth

smtp_sasl_security_options = noanonymous

smtp_tls_mandatory_protocols = !SSLv2 !SSLv3

smtp_tls_protocols = !SSLv2, !SSLv3

smtp_tls_security_level = may

smtpd_banner = $myhostname ESMTP $mail_name

smtpd_tls_mandatory_protocols = !SSLv2 !SSLv3

smtpd_tls_protocols = !SSLv2 !SSLv3

transport_maps = hash:/etc/postfix/transport_maps

unknown_local_recipient_reject_code = 550

 

In the main.cf this entry "content_filter = klms_postfix-afterqueue:127.0.0.1:10025" is needed for the KLMS filter

 

master.cf:

The excerpts displaying the three filters:

# spamassassin

spamassassin unix -     n       n       -       -       pipe

        user=debian-spamd argv=/usr/bin/spamc -f -e /usr/sbin/sendmail -oi -f ${sender} ${recipient}

 

# AV scan filter (used by content_filter)

scan      unix  -       -       n       -       16      smtp

        -o smtp_send_xforward_command=yes

        -o smtp_enforce_tls=no

 

#klms-begin-afterqueue-filter

klms_postfix-afterqueue unix    -       -       n        -      10      smtp

        -o smtp_send_xforward_command=yes

127.0.0.1:10026 inet    n       -       n       -       10      smtpd

        -o content_filter=

        -o content_filter=scan:[127.0.0.1]:10027

        -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks

        -o smtpd_helo_restrictions=

        -o smtpd_client_restrictions=

        -o smtpd_sender_restrictions=

        -o smtpd_recipient_restrictions=permit_mynetworks,reject

        -o mynetworks=127.0.0.0/8,[::1]/128

        -o smtpd_authorized_xforward_hosts=127.0.0.0/8,[::1]/128

#klms-end-afterqueue-filter

 

# For injecting mail back into postfix from the filter

127.0.0.1:10028 inet  n -       n       -       16      smtpd

        -o content_filter=

        -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks,no_address_mappings

        -o smtpd_helo_restrictions=

        -o smtpd_client_restrictions=

        -o smtpd_sender_restrictions=

        -o smtpd_recipient_restrictions=permit_mynetworks,reject

        -o mynetworks_style=host

        -o smtpd_authorized_xforward_hosts=127.0.0.0/8

                       

Note that I did not change the master.cf and main.cf back to it's default values speaking of the "no_address_mappings" directive.

I carefully implemented that directive at any place that seemed logical to me, to no avail.

 

Debugging the issue by making the smtpd -v and -vv generated more output that was logged, however it did not help me understand where the issue comes from.

 

Could anybody shed some light on this issue?

Any help is appreciated, if more logfiles / information is needed, just ask.

 

Regards,

Niclas

 


Reply | Threaded
Open this post in threaded view
|

Re: Duplicate mails in mailq / always_bcc

Viktor Dukhovni


> On Nov 27, 2017, at 8:29 AM, GP <[hidden email]> wrote:
>
>> 5086760443    35318 Mon Nov 13 16:04:20  [hidden email]
>>
>> (lost connection with 192.168.N.NN[192.168.N.NN] while sending end of data -- message may be sent more than once)
>>
>>                                          [hidden email]

What's missing from this problem report is the logging for queue-id
5086760443, which would show the timing of the lost connection.  Perhaps
the sending Postfix needs a more generous timeout.

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Duplicate mails in mailq / always_bcc

Wietse Venema
In reply to this post by Niclas Rautenhaus
Niclas Rautenhaus:
> 5086760443    35318 Mon Nov 13 16:04:20  [hidden email]<mailto:[hidden email]>
> (lost connection with 192.168.N.NN[192.168.N.NN] while sending end of data -- message may be sent more than once)

This is the result of Postfix reading EOF, not a Postfix timeout
(that produces a different error message).

Postfix may read EOF as the result of some other error at a lower
layer in the network stack.

A more precise determination would require a network sniffer. Just
the packet metadata (no data content) might be sufficient.

        Wietse
Reply | Threaded
Open this post in threaded view
|

AW: [MASSMAIL]Re: Duplicate mails in mailq / always_bcc

Niclas Rautenhaus



Hi list,

sorry for my belated reply.

First of all: thanks for the input to everyone suggesting where  / what the error may be.

What I tried so far:
1) reducing the MTU all the way down to 1400 - no change, error still persists.

I will now proceed troubleshooting by sniffing the network communication, maybe I am able to gather clues doing so...






-----Ursprüngliche Nachricht-----
Von: [hidden email] [mailto:[hidden email]] Im Auftrag von Wietse Venema
Gesendet: Montag, 27. November 2017 21:39
An: Postfix users <[hidden email]>
Betreff: [MASSMAIL]Re: Duplicate mails in mailq / always_bcc

Niclas Rautenhaus:
> 5086760443    35318 Mon Nov 13 16:04:20  [hidden email]<mailto:[hidden email]>
> (lost connection with 192.168.N.NN[192.168.N.NN] while sending end of
> data -- message may be sent more than once)

This is the result of Postfix reading EOF, not a Postfix timeout (that produces a different error message).

Postfix may read EOF as the result of some other error at a lower layer in the network stack.

A more precise determination would require a network sniffer. Just the packet metadata (no data content) might be sufficient.

        Wietse