Hi again Wietse,
as you pointed out we have "smtpd_delay_reject=no" configured in our "master.cf" as it is suggested for integration of amavisd-new with postfix:
https://www.ijs.si/software/amavisd/README.postfix.html#filter_service_global
We have tried setting the parameter to "yes" but we don't see any improvements. Still we don't think that this is the place where we have to change this parameter, but instead it should be added in "main.cf" where we have the actual "smtpd_client_restrictions"??
So we have tried including the line "smtpd_delay_reject=yes" (default value is "yes") in "main.cf", but here also we don't see any differences...
We have been using "smtp-source" mail generator to simulate different mail-flows and please see below the results, do you see anything particular?
We have made a comparison between "sqlgrey" and "policyd-spf" policies, to see the mail rates are comparable with the policy calls and we see that at slow rates counters are almos identical, but for higher rates "sqlgrey" policy keeps up whereus "policyd-spf" does not....
And finally at a very high rate of mails non of them works well...
Are we seeing some kind of defect in the "policyd-spf" policy maybe?
We are very interested in your opinion.
Thank you,
# One session per delivery, slowly:
smtp-source -s 1 -m 10 -w 10 -t recipient host:port
### with smtpd_delay_reject=yes (main.cf)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 10 (expected 10)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 9 (expected 10)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 10 (expected 10)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 9 (expected 10)
# One session for all deliveries, slowly:
smtp-source -s 1 -m 10 -w 10 -d -t recipient host:port
### with smtpd_delay_reject=yes (main.cf)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 10 (expected 10)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 9 (expected 10)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 10 (expected 10)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 10 (expected 10)
policyd-spf_policy_calls --> 9 (expected 10)
# Ten parallel sessions, multiple deliveries per session, slowly:
smtp-source -s 10 -m 100 -w 10 -d -t recipient host:port
### with smtpd_delay_reject=yes (main.cf)
sqlgrey_policy_calls --> 100 (expected 100)
policyd-spf_policy_calls --> 100 (expected 100)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 100 (expected 100)
policyd-spf_policy_calls --> 100 (expected 100)
sqlgrey_policy_calls --> 100 (expected 100)
policyd-spf_policy_calls --> 100 (expected 100)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 100 (expected 100)
policyd-spf_policy_calls --> 100 (expected 100)
# One session at a time, multiple deliveries per session, fast:
smtp-source -s 1 -m 1000 -d -t recipient host:port
### with smtpd_delay_reject=yes (main.cf)
sqlgrey_policy_calls --> 996 (expected 1000)
policyd-spf_policy_calls --> 91 (expected 1000)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 999 (expected 1000)
policyd-spf_policy_calls --> 92 (expected 1000)
sqlgrey_policy_calls --> 996 (expected 1000)
policyd-spf_policy_calls --> 91 (expected 1000)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 999 (expected 1000)
policyd-spf_policy_calls --> 92 (expected 1000)
# Ten parallel sessions, multiple deliveries per session, fast:
smtp-source -s 10 -m 10000 -d -t recipient host:port
### with smtpd_delay_reject=yes (main.cf)
sqlgrey_policy_calls --> 5868 (expected 10000)
policyd-spf_policy_calls --> 1090 (expected 10000)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 5570 (expected 10000)
policyd-spf_policy_calls --> 1065 (expected 10000)
sqlgrey_policy_calls --> 5868 (expected 10000)
policyd-spf_policy_calls --> 1090 (expected 10000)
### with smtpd_delay_reject=no (main.cf)
sqlgrey_policy_calls --> 5570 (expected 10000)
policyd-spf_policy_calls --> 1065 (expected 10000)
eNeKuX
Sent: Monday, June 06, 2016 at 10:01 PM
From: eNeKuX <ene...@gmx.com>
To: postfix-users@postfix.org
Subject: Re: Problems with SPF policy service (pypolicyd-spf)
From: eNeKuX <ene...@gmx.com>
To: postfix-users@postfix.org
Subject: Re: Problems with SPF policy service (pypolicyd-spf)
Hello and thank you for your reply.
I have followed your suggestions for debugging and please find below this message the results.
I see a general pattern for all the tests, no matter if "smtpd_delay_reject" is set to "no" or "yes", the number of policy calls are not equal to the message rate...
Any ideas why would this happen?
# One session per delivery, slowly:
smtp-source -s 1 -m 10 -w 10 -t recipient host:port
smtp-source -s 1 -m 10 -w 10 -t recipient host:port
### with smtpd_delay_reject=no
cat counter_test1.txt | wc -l --> 5 (expected 10)
### with smtpd_delay_reject=yes
cat counter_test1.txt | wc -l --> 5 (expected 10)
cat counter_test1.txt | wc -l --> 5 (expected 10)
### with smtpd_delay_reject=yes
cat counter_test1.txt | wc -l --> 5 (expected 10)
# One session for all deliveries, slowly:
smtp-source -s 1 -m 10 -w 10 -d -t recipient host:port
### with smtpd_delay_reject=no
cat counter_test2.txt | wc -l --> 5 (expected 10)
### with smtpd_delay_reject=yes
cat counter_test2.txt | wc -l --> 5 (expected 10)
cat counter_test2.txt | wc -l --> 5 (expected 10)
### with smtpd_delay_reject=yes
cat counter_test2.txt | wc -l --> 5 (expected 10)
# Ten parallel sessions, multiple deliveries per session, slowly:
smtp-source -s 10 -m 100 -w 10 -d -t recipient host:port
### with smtpd_delay_reject=no
cat counter_test3.txt | wc -l --> 92 (expected 100)
### with smtpd_delay_reject=yes
cat counter_test3.txt | wc -l --> 92 (expected 100)
cat counter_test3.txt | wc -l --> 92 (expected 100)
### with smtpd_delay_reject=yes
cat counter_test3.txt | wc -l --> 92 (expected 100)
# One session at a time, multiple deliveries per session, fast:
smtp-source -s 1 -m 1000 -d -t recipient host:port
### with smtpd_delay_reject=no
cat counter_test4.txt | wc -l --> 102 (expected 1000)
### with smtpd_delay_reject=yes
cat counter_test4.txt | wc -l --> 108 (expected 1000)
cat counter_test4.txt | wc -l --> 102 (expected 1000)
### with smtpd_delay_reject=yes
cat counter_test4.txt | wc -l --> 108 (expected 1000)
# Ten parallel sessions, multiple deliveries per session, fast:
smtp-source -s 10 -m 10000 -d -t recipient host:port
### with smtpd_delay_reject=no
cat counter_test5.txt | wc -l --> 1339 (expected 10000)
### with smtpd_delay_reject=yes
cat counter_test5.txt | wc -l --> 1311 (expected 10000)
cat counter_test5.txt | wc -l --> 1339 (expected 10000)
### with smtpd_delay_reject=yes
cat counter_test5.txt | wc -l --> 1311 (expected 10000)
eNeKuX
Sent: Saturday, June 04, 2016 at 11:57 PM
From: "Wietse Venema" <wie...@porcupine.org>
To: "Postfix users" <postfix-users@postfix.org>
Subject: Re: Problems with SPF policy service (pypolicyd-spf)
From: "Wietse Venema" <wie...@porcupine.org>
To: "Postfix users" <postfix-users@postfix.org>
Subject: Re: Problems with SPF policy service (pypolicyd-spf)
eNeKuX:
> Hi there,
>
> we are experiencing an strange behaviour of a SPF policy service
> "pypolicyd-spf" on debian-wheezy (v1.0-2).
>
> We have reported the issue at their side
> (https://bugs.launchpad.net/pypolicyd-spf/+bug/1587173) but they
> are pointing us to report it here.
>
>
> When our server is running in our testing environment with near
> "0" mailflow the SPF policy service kicks-in for every incoming
> email and works as expected. Instead, if we move our server to
> production (same server, same configuration but with different IP)
> where there is a high mailflow, the SPF policy service does not
> kick-in for every incoming email but some is processed every 2 to
> 10 minutes.
You have configured smtpd_delay_reject=no. That completely changes
the way that smtpd_client_restrictions is evaluated. Instead of
once per recipient, it is evaluated only once per SMTP session, and
it is evaluated before Postfix has seen the EHLO, MAIL FROM, and
RCPT TO commands.
To debug, I suggest that you do some experiments in the test machine.
Use a mail generator such as smtp-source to demonstrate that Postfix
makes all expected policy calls at all message rates, whether the
mail arrives in parallel or not.
# One session per delivery, slowly:
smtp-source -s 1 -m 10 -w 10 -t recipient host:port
# One session for all deliveries, slowly:
smtp-source -s 1 -m 10 -w 10 -d -t recipient host:port
# Ten parallel sessions, multiple deliveries per session, slowly:
smtp-source -s 10 -m 100 -w 10 -d -t recipient host:port
# One session at a time, multiple deliveries per session, fast:
smtp-source -s 1 -m 1000 -d -t recipient host:port
# Ten parallel sessions, multiple deliveries per session, fast:
smtp-source -s 10 -m 10000 -d -t recipient host:port
smtp-source is part of Postfix source code. It is usually not
installed, because it is an unsupported test program.
Wietse
> Hi there,
>
> we are experiencing an strange behaviour of a SPF policy service
> "pypolicyd-spf" on debian-wheezy (v1.0-2).
>
> We have reported the issue at their side
> (https://bugs.launchpad.net/pypolicyd-spf/+bug/1587173) but they
> are pointing us to report it here.
>
>
> When our server is running in our testing environment with near
> "0" mailflow the SPF policy service kicks-in for every incoming
> email and works as expected. Instead, if we move our server to
> production (same server, same configuration but with different IP)
> where there is a high mailflow, the SPF policy service does not
> kick-in for every incoming email but some is processed every 2 to
> 10 minutes.
You have configured smtpd_delay_reject=no. That completely changes
the way that smtpd_client_restrictions is evaluated. Instead of
once per recipient, it is evaluated only once per SMTP session, and
it is evaluated before Postfix has seen the EHLO, MAIL FROM, and
RCPT TO commands.
To debug, I suggest that you do some experiments in the test machine.
Use a mail generator such as smtp-source to demonstrate that Postfix
makes all expected policy calls at all message rates, whether the
mail arrives in parallel or not.
# One session per delivery, slowly:
smtp-source -s 1 -m 10 -w 10 -t recipient host:port
# One session for all deliveries, slowly:
smtp-source -s 1 -m 10 -w 10 -d -t recipient host:port
# Ten parallel sessions, multiple deliveries per session, slowly:
smtp-source -s 10 -m 100 -w 10 -d -t recipient host:port
# One session at a time, multiple deliveries per session, fast:
smtp-source -s 1 -m 1000 -d -t recipient host:port
# Ten parallel sessions, multiple deliveries per session, fast:
smtp-source -s 10 -m 10000 -d -t recipient host:port
smtp-source is part of Postfix source code. It is usually not
installed, because it is an unsupported test program.
Wietse
