Milter-greylist

On Dec 5, 2015, at 11:28 PM, manu@... [milter-greylist] <milter-greylist@yahoogroups.com> wrote:
> Try replacing the " (ACL %a)" by " (ACL %A )", this will always display the line
> number and never the ACL id string. That will let us have a definitive answer on
> what ACL matches. 

Dec 06 10:25:46 xxx milter-greylist[19837]: tB6FPku6019844: addr xxx[xxx] from <xxx> to <xxx> delayed for 00:30:00 (ACL (none))

This matches my suspicion that some default racl is matching that is not in my config file.

In case there is any doubt:

$ ps faxuwww | grep [g]reylist
grmilter 19837  0.0  0.1 322136  4224 ?        Ssl  10:25   0:00 /usr/sbin/milter-greylist -D

The greylist.conf is exactly as I posted it on Friday.

So what’s happening?  I think real_envrcpt is signaling to TEMPFAIL in the default case (no previous greylisting, no autowhitelisting, no blacklisting), so real_eom does not have a chance to affect the message disposition.

RCPT phase:
 mlfi_envrcpt -> real_envrcpt -> acl_filter(AS_RCPT)
 /* SHOULD signal to continue unless DEFINITIVE action was taken */

DATA phase:
  mlfi_eom -> real_eom -> acl_filter(AS_DATA)
  /* SHOULD be given the chance to take action unless definitive action was taken in RCPT phase */

Some details from the code:

acl.c:acl_filter()
   2438         if (acl == NULL) {
   2439                 /*
   2440                  * No match: use the default action
   2441                  */
   2442                 if (testmode)
   2443                         retval = EXF_WHITELIST;
   2444                 else if (stage == AS_DATA)
   2445                         retval = EXF_WHITELIST | EXF_NOLOG;
   2446                 else
   2447                         retval = EXF_GREYLIST;
   2448                 retval |= EXF_DEFAULT;
   2449 
   2450                 priv->priv_sr.sr_delay = conf.c_delay;
   2451                 priv->priv_sr.sr_autowhite = conf.c_autowhite_validity;
   2452                 priv->priv_sr.sr_tarpit = conf.c_tarpit;
   2453                 priv->priv_sr.sr_tarpit_scope = conf.c_tarpit_scope;
   2454         }

   2557         error = 0;

   2561         priv->priv_sr.sr_whitelist = retval;
   2562 
   2563         return error;
   2564 }

When there is no racl match, we will greylist (and when there is no setting for the delay, we get the default of 30m (GLDELAY).

milter-greylist.c:real_envrcpt()
    725         if (acl_filter(AS_RCPT, ctx, priv) != 0) {
    726                 mg_log(LOG_ERR, "ACL evaluation failure");
    727                 return SMFIS_TEMPFAIL;
    728         }

acl_filter will have returned 0, so we continue…

priv->priv_sr.sr_wrhitelist will be EXF_GREYLIST | EXF_DEFAULT (for the the first time this tuple has been encountered)

    730         if (priv->priv_sr.sr_whitelist & EXF_WHITELIST &&
    731             priv->priv_sr.sr_tarpit <= 0) {
    732                 priv->priv_sr.sr_elapsed = 0;
    733                 goto exit_accept;
    734         }

not whitelisted or blacklisted so we continue…

    763          * Check if the tuple {sender IP, sender e-mail, recipient e-mail}
    764          * is in the greylist or autowhite list and if it can now be 
    765          * accepted. If in greylist, the greylist entry will change to 
    766          * autowhite entry. If it is not in the greylist, it will be added.
    767          */
    768 
    769         tuple.sa = SA(&priv->priv_addr);
    770         tuple.salen = priv->priv_addrlen;
    771         tuple.from = priv->priv_from;
    772         tuple.rcpt = rcpt;
    773         tuple.remaining = &remaining;
    774         tuple.elapsed = &priv->priv_sr.sr_elapsed;
    775         tuple.queueid = priv->priv_queueid;
    776         tuple.gldelay = priv->priv_sr.sr_delay;
    777         tuple.autowhite = priv->priv_sr.sr_autowhite;
    778 
    779         switch(mg_tuple_check(&tuple)) {

first time through, so we’ll take the default case:

    790         default:                        /* first encounter */
    791                 if (!(priv->priv_sr.sr_whitelist & EXF_TARPIT))
    792                         break;

not tarpitted so we break out of the case statement here

    818         /*
    819          * The message has been added to the greylist and will be delayed.
    820          * If the sender address is null, this will be done after the DATA
    821          * phase, otherwise immediately.
    822          * Delayed reject with per-recipient delays or messages 
    823          * will use the last match.
    824          */
    825         if ((conf.c_delayedreject == 1) && 
    826             (strcmp(priv->priv_from, "<>") == 0)) {
    827                 priv->priv_delayed_reject = 1;
    828                 goto exit_accept;
    829         }
    830 
    831         /*
    832          * Log temporary failure and report to the client.
    833          */
    834         priv->priv_sr.sr_whitelist |= save_nolog;
    835         log_and_report_greylisting(ctx, priv, *envrcpt);
    836         return mg_stat(priv, SMFIS_TEMPFAIL);

There you have it: we have reported back through the milter interface that the message should be TEMPFAILed, and we haven’t even consulted our dacls.

So, if we have been greylisted already and are retrying, how does that change things?

    779         switch(mg_tuple_check(&tuple)) {

    785         case T_PENDING:                 /* greylisted */
    786                 if (priv->priv_sr.sr_elapsed > priv->priv_max_elapsed)
    787                         priv->priv_max_elapsed = priv->priv_sr.sr_elapsed;
    788                 goto exit_accept;
    789                 break;

Let’s assume our delay period has elapsed:

    838 exit_accept:
    839         add_recipient(priv, rcpt);
    840         if (priv->priv_sr.sr_whitelist & EXF_WHITELIST)
    841                 priv->priv_last_whitelist = priv->priv_sr.sr_whitelist;
    842         return SMFIS_CONTINUE;
    843 }

So in this case we SHOULD be able to have actions in our dacls take effect, because the RCPT phase hasn’t TEMPFAILed…

milter-greylist.c:real_body()
   1142         if (priv->priv_sr.sr_whitelist & EXF_WHITELIST && 
   1143             priv->priv_sr.sr_whitelist & EXF_DEFAULT)
   1144                 envrcpt_continue = 1;

Remember, we are EXF_GREYLIST | EXF_DEFAULT, so this does not match.

  1152         /* 2015-12-05 debugging per manu@... */
   1153         mg_log(LOG_ERR, "I was here");
   1154         if (acl_filter(AS_DATA, ctx, priv) != 0) {
   1155                 mg_log(LOG_ERR, "ACL evaluation failure");
   1156                 return SMFIS_TEMPFAIL;
   1157         }

   1159         if (priv->priv_sr.sr_whitelist & EXF_BLACKLIST) {

Not us

   1190         if (priv->priv_sr.sr_whitelist & EXF_GREYLIST && envrcpt_continue) {

Not us either, because envrcpt_continue was NOT set on line 1144

   1237 passed:
   1238         /* Add custom header from DATA stage ACL */
   1239         /* XXX we do it twice??? */
   1240         if (priv->priv_sr.sr_addheader) {

skipping more code that doesn’t match our case

   1342         if (priv->priv_max_elapsed == 0) {
   1343                 /* All recipients are whitelisted */

Hmm?  This was set to 0 initially in real_connect(), and otherwise set to priv->priv_sr.sr_elapsed.  priv->priv_sr.sr_elapsed would be set to 0 for non-network connections and for authenticated connections (and SPF, DRAC, or access DB matches if we are using those but we aren’t); also for whitelisted entries but we’re not whitelisted (don’t have EXF_WHITELIST set still).  So otherwise we expect it to get set to priv->priv_max_elapsed in real_eom.  I’m out of time to trace how this work, but if we end up with priv_max_elapsed == 0 here, so maybe that’s the problem.  Anyway I will get some additional debugging set in milter-greylist since I see some logging that would be helpful here.

Thanks,
Rudy