address_verify_negative_refresh_time = 30m is ignored

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

address_verify_negative_refresh_time = 30m is ignored

Stefan Bauer-2
hi,

we have

address_verify_negative_refresh_time = 30m active
(root@mx2:/var/lib/postfix# postconf -n | grep verify
address_verify_negative_refresh_time = 30m)
but the verify behavior is strange.

Jan 23 21:15:21 mx2 postfix/postscreen[Jan 25 15:31:14 mx2 postfix/smtpd[10119]: NOQUEUE: reject: RCPT from opsmail.colo.comodo.com[91.209.196.133]: 550 5.1.1 <[hidden email]: Recipient address rejected: undeliverable address: host IP[IP] said: 550 5.1.1 <[hidden email]: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command); from=<[hidden email]> to=<[hidden email] proto=ESMTP helo=<mcmail3.mcr.colo.comodo.net>
Jan 25 15:31:14 mx2 postfix/smtpd[10117]: NOQUEUE: reject: RCPT from opsmail.colo.comodo.com[91.209.196.133]: 550 5.1.1 <[hidden email]: Recipient address rejected: undeliverable address: host IP[IP] said: 550 5.1.1 <[hidden email]: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command); from=<[hidden email]> to=<[hidden email] proto=ESMTP helo=<mcmail3.mcr.colo.comodo.net>
Jan 25 15:31:14 mx2 postfix/smtp[10124]: 2CFE27E3A2: to=<[hidden email], relay=IP[IP]:25, delay=0.25, delays=0/0.01/0.21/0.03, dsn=2.1.5, status=deliverable (250 2.1.5 Ok)


I dont see a veify request at 15:31 at the remote site. why is postfix still caching verify results but report instead after client was rejected, that the address is deliverable?


thank you.
Reply | Threaded
Open this post in threaded view
|

Re: address_verify_negative_refresh_time = 30m is ignored

Wietse Venema
Stefan Bauer:

> Jan 25 15:31:14 mx2 postfix/smtpd[10117]: NOQUEUE: reject: RCPT from
> opsmail.colo.comodo.com[91.209.196.133]: 550 5.1.1
> <[hidden email]: Recipient address rejected: undeliverable
> address: host IP[IP] said: 550 5.1.1 <[hidden email]: Recipient
> address rejected: User unknown in virtual mailbox table (in reply to
> RCPT TO command); from=<[hidden email]>
> to=<[hidden email] proto=ESMTP
> helo=<mcmail3.mcr.colo.comodo.net>
> Jan 25 15:31:14 mx2 postfix/smtp[10124]: 2CFE27E3A2:
> to=<[hidden email], relay=IP[IP]:25, delay=0.25,
> delays=0/0.01/0.21/0.03, dsn=2.1.5, status=deliverable (250 2.1.5 Ok)

The second logfile record shows that a new probe was sent with queue
ID 2CFE27E3A2 (the old result had expired, or it was older than
half the expiration time), and the probe result was 'deliverable'.

If the old result was expired, then it would be a surprise that the
expired result was returned to smtpd. Normally, an expired result
is supposed to be ignored, as if the result did not exist.

If the result was older than half the expiration time but not
expired, then it would be OK to return the old probe result to
smtpd.

> I dont see a veify request at 15:31 at the remote site. why is postfix
> still caching verify results but report instead after client was
> rejected, that the address is deliverable?

The probe had queue ID 2CFE27E3A2. Look in your mail logfile.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: address_verify_negative_refresh_time = 30m is ignored

Stefan Bauer-2
thank you. seems to be that

if address_verify_negative_refresh_time = 30m, the next attempt to reach a specific recipient that is negative in cache, will still get the "old" answer from cache if it is not expired by address_verify_negative_expire_time. that is default 3d.
so in my case, postfix was doing a new verify, but reported the old results from cache.

I was expecting that postfix would always do a new probe and not just handing out old results even though it lears right after this, new results.

Am Fr., 25. Jan. 2019 um 16:33 Uhr schrieb Wietse Venema <[hidden email]>:
Stefan Bauer:
> Jan 25 15:31:14 mx2 postfix/smtpd[10117]: NOQUEUE: reject: RCPT from
> opsmail.colo.comodo.com[91.209.196.133]: 550 5.1.1
> <[hidden email]: Recipient address rejected: undeliverable
> address: host IP[IP] said: 550 5.1.1 <[hidden email]: Recipient
> address rejected: User unknown in virtual mailbox table (in reply to
> RCPT TO command); from=<[hidden email]>
> to=<[hidden email] proto=ESMTP
> helo=<mcmail3.mcr.colo.comodo.net>
> Jan 25 15:31:14 mx2 postfix/smtp[10124]: 2CFE27E3A2:
> to=<[hidden email], relay=IP[IP]:25, delay=0.25,
> delays=0/0.01/0.21/0.03, dsn=2.1.5, status=deliverable (250 2.1.5 Ok)

The second logfile record shows that a new probe was sent with queue
ID 2CFE27E3A2 (the old result had expired, or it was older than
half the expiration time), and the probe result was 'deliverable'.

If the old result was expired, then it would be a surprise that the
expired result was returned to smtpd. Normally, an expired result
is supposed to be ignored, as if the result did not exist.

If the result was older than half the expiration time but not
expired, then it would be OK to return the old probe result to
smtpd.

> I dont see a veify request at 15:31 at the remote site. why is postfix
> still caching verify results but report instead after client was
> rejected, that the address is deliverable?

The probe had queue ID 2CFE27E3A2. Look in your mail logfile.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: address_verify_negative_refresh_time = 30m is ignored

Wietse Venema
Stefan Bauer:
> thank you. seems to be that
>
> if address_verify_negative_refresh_time = 30m, the next attempt to reach a
> specific recipient that is negative in cache, will still get the "old"
> answer from cache if it is not expired by
> address_verify_negative_expire_time. that is default 3d.

I just looked things up (I wrote this code more than 10 years ago!),
and I conclude that you misunderstand the difference between
EXPIRATION time and REFRESH time.

As long as the stored result is not expired, the stored result is
returned to smtpd. That is what expiration means.

After the non-expired result is returned to smtpd, a refresh may
happen when the non-expired result is older than some positive
or negative refresh time. That is what refresh means.

But it would be stupid to block the smtpd while the refresh for a
NON-EXPIRED result is in progress, because then you might just as
well have a very short expire time.

        Wietse


Reply | Threaded
Open this post in threaded view
|

Re: address_verify_negative_refresh_time = 30m is ignored

Stefan Bauer-2
Thank you Wietse for taking the time to explain things. I really appreciate this. now all is clear.

Am Freitag, 25. Januar 2019 schrieb Wietse Venema <[hidden email]>:

> Stefan Bauer:
>> thank you. seems to be that
>>
>> if address_verify_negative_refresh_time = 30m, the next attempt to reach a
>> specific recipient that is negative in cache, will still get the "old"
>> answer from cache if it is not expired by
>> address_verify_negative_expire_time. that is default 3d.
>
> I just looked things up (I wrote this code more than 10 years ago!),
> and I conclude that you misunderstand the difference between
> EXPIRATION time and REFRESH time.
>
> As long as the stored result is not expired, the stored result is
> returned to smtpd. That is what expiration means.
>
> After the non-expired result is returned to smtpd, a refresh may
> happen when the non-expired result is older than some positive
> or negative refresh time. That is what refresh means.
>
> But it would be stupid to block the smtpd while the refresh for a
> NON-EXPIRED result is in progress, because then you might just as
> well have a very short expire time.
>
>         Wietse
>
>
>