[Sqlgrey-users] Re: Strange sqlgrey behaviour

[Lionel B. <lio...@bo...>]

Alexey Grigoriev wrote the following on 10/18/04 16:55 :

> Hello. I had no time to prepare debian packages this weekend but found 
> some strange feature in postgrey behaviour.
> My question is: When does sqlgrey clear his connection cache? At 
> startup? I've got a lof of records in a connect table. And they 
> disappear only after restarting sqlgrey.
>

It seems someting is actually wrong with the cleanup. This is not a 
major problem on low volume sites, as this can only affect SELECT from 
connect times and not the results.

sqlgrey should clean the connect table on 2 occasions :
- at startup,
- when it is handling a request and a cleanup wasn't triggered for 24 
hours (was changed in recent releases, previously the delay was set to 
15 minutes).

I witnessed an odd behaviour with a previous version weeks ago where 
sqlgrey seemed to forget to do cleanups. I didn't understand why and 
couldn't reproduce this behaviour since then.

The code involved is pretty simple on each request sqlgrey does the 
following :

    if (time() > ($self->{sqlgrey}{last_maint} +
                  $self->{sqlgrey}{maint_delay})
       ) {
        $self->log(4, "Maintenance delay expired: cleanup triggered");
        $self->cleanup();
        $self->{sqlgrey}{last_maint} = time();
    }

$self->{sqlgrey}{maint_delay} is set to 86400 at startup time and 
$self->{sqlgrey}{last_maint} is initially set to the current time.
A grep on "maint" in the code shows that these are the only places 
"last_maint" and "maint_delay" are used.

If you start sqlgrey with "-v" or "--verbose" the $self->log ligne will 
actually send the message to syslog (there's a filter on the loglevel) 
and you can verify that a cleanup is triggered.
Anyway, on each cleanup, sqlgrey logs the failed transmissions attempts 
like this :

Oct 11 23:44:32 xxxxx sqlgrey[ddddd]: Probable spam: 66.117.40.12: 
xxxxxx@spammer_domain.tld -> lio...@bo... at 2004-10-10 
15:17:19.439293

The log above doesn't match with the intent of the code : I had some 
connections between Oct 11 15:17:19 (24 hours after the connection 
according to this log) and the date of the log line ("Oct 11 23:44:32").
So there is a problem but I can't put a finger on it yet. I'll try 
debugging it on my MX by logging each time value involved in the piece 
of code above whenever they are used.
Meanwhile, unless you want to help debugging the problem, my advice is 
to set a cron job to restart sqlgrey regularly.

Note :
$self->cleanup() actually handles the AWL cleanups as well.

Please CC: the sqlgrey-users mailing-list, as others are most probably 
affected. I'll open a bug on sourceforge right away.

Best regards,

Lionel.