On Mon, Apr 27, 2015, at 10:43 PM, Adam Wolk wrote:
> On Mon, Apr 27, 2015, at 10:22 PM, Todd C. Miller wrote:
> > On Mon, 27 Apr 2015 20:06:59 +0200, Adam Wolk wrote:
> >
> > > Apr 27 19:54:55 tintagel spamd[27724]: can't delete 66.111.4.25
> > > out1-smtp.messagingengine.com <adam.w...@koparo.com>
> > > <adam.w...@tintagel.pl> from spamd db (Error 22)
> > >
> > > Does anyone know how serious that error is (should I be worried) and
> > > what might have caused it?
> >
> > Error 22 is EINVAL. I'm not sure how that can happen in this case
> > though. Have you tried restating spamd?
> >
>
> Hi Todd,
>
> Indeed I tried restarting spamd and the issue is the same each time.
> With a spamd restart the error happens immediately startup:
>
> Apr 27 22:27:52 tintagel spamd[3732]: can't delete 66.111.4.25
> out1-smtp.messagingengine.com <adam.w...@koparo.com>
> <adam.w...@tintagel.pl> from spamd db (Error 0)
> Apr 27 22:28:51 tintagel spamd[25915]: listening for incoming
> connections.
> Apr 27 22:28:51 tintagel spamd[7233]: can't delete 66.111.4.25
> out1-smtp.messagingengine.com <adam.w...@koparo.com>
> <adam.w...@tintagel.pl> from spamd db (Error 0)
>
Just noticed, that right after a previous restart it's no longer Error
22 but Error 0
Apr 27 21:50:27 tintagel spamd[27724]: can't delete 66.111.4.25
out1-smtp.messagingengine.com <adam.w...@koparo.com>
<adam.w...@tintagel.pl> from spamd db (Error 22)
Apr 27 21:51:27 tintagel spamd[27724]: can't delete 66.111.4.25
out1-smtp.messagingengine.com <adam.w...@koparo.com>
<adam.w...@tintagel.pl> from spamd db (Error 22)
Apr 27 21:52:18 tintagel spamd[8450]: listening for incoming
connections.
Apr 27 21:52:18 tintagel spamd[20180]: can't delete 66.111.4.25
out1-smtp.messagingengine.com <adam.w...@koparo.com>
<adam.w...@tintagel.pl> from spamd db (Error 0)
Apr 27 21:52:25 tintagel spamd[6924]: listening for incoming
connections.
Apr 27 21:52:25 tintagel spamd[3732]: can't delete 66.111.4.25
out1-smtp.messagingengine.com <adam.w...@koparo.com>
<adam.w...@tintagel.pl> from spamd db (Error 0)
Apr 27 21:53:26 tintagel spamd[3732]: can't delete 66.111.4.25
out1-smtp.messagingengine.com <adam.w...@koparo.com>
<adam.w...@tintagel.pl> from spamd db (Error 0)
Apr 27 21:54:26 tintagel spamd[3732]: can't delete 66.111.4.25
out1-smtp.messagingengine.com <adam.w...@koparo.com>
<adam.w...@tintagel.pl> from spamd db (Error 0)
Apr 27 21:55:27 tintagel spamd[3732]: can't delete 66.111.4.25
out1-smtp.messagingengine.com <adam.w...@koparo.com>
<adam.w...@tintagel.pl> from spamd db (Error 0)
# ls -l /var/db/spamd
-rw-r--r-- 1 _spamd _spamd 6881280 Apr 27 22:51 /var/db/spamd
here's my process output limited to spamd
# ps aux | grep -i spamd
root 30279 0.0 3.3 68000 67956 ?? Ss Sun11PM 1:22.68 perl:
/usr/local/bin/spamd -d -u _spamdaemon -P (perl)
_spamdaemon 10621 0.0 0.4 68016 8872 ?? S Sun11PM 0:00.59
perl: spamd child (perl)
_spamdaemon 29838 0.0 0.4 68016 8936 ?? S Sun11PM 0:00.83
perl: spamd child (perl)
_spamd 7233 0.0 0.1 9860 1704 ?? Is 10:28PM 0:00.73 spamd:
(pf <spamd-white> update) (spamd)
_spamd 25915 0.0 0.3 10308 5220 ?? I 10:28PM 0:00.12 spamd:
[priv] (greylist) (spamd)
_spamd 14894 0.0 0.0 9656 1020 ?? I 10:28PM 0:00.00 spamd:
(/var/db/spamd update) (spamd)
root 30162 0.0 0.0 636 4 p7 R+ 10:52PM 0:00.00 grep
-i spamd (ksh)
#
> > You might also try running:
> >
> > $ spamdb | fgrep 66.111.4.25
>
> Here is the output:
> $ spamdb | fgrep 66.111.4.25
> WHITE|66.111.4.25|||1430096342|1430098533|1433208963|4|0
> GREY|66.111.4.25|out1-smtp.messagingengine.com|<adam.w...@koparo.com>|<mulan...@tintagel.pl>|1430146234|1430148635|1430160634|3|0
> GREY|66.111.4.25|out1-smtp.messagingengine.com|<adam.w...@koparo.com>|<mulan...@tintagel.pl>|1430146234|1430148635|1430160634|3|0
> GREY|66.111.4.25|out1-smtp.messagingengine.com|<adam.w...@koparo.com>|<adam.w...@tintagel.pl>|1430142855|1430145035|1430157255|4|0
>
>
> >
> > to see if that entry is really in the database and if so see if
> > "spamdb -d" can remove it.
> >
>
> # spamdb -d 66.111.4.25
> # echo $?
> 0
> # spamdb | fgrep 66.111.4.25
> WHITE|66.111.4.25|||1430096342|1430098533|1433208963|4|0
> GREY|66.111.4.25|out1-smtp.messagingengine.com|<adam.w...@koparo.com>|<mulan...@tintagel.pl>|1430146234|1430148635|1430160634|3|0
> GREY|66.111.4.25|out1-smtp.messagingengine.com|<adam.w...@koparo.com>|<mulan...@tintagel.pl>|1430146234|1430148635|1430160634|3|0
> GREY|66.111.4.25|out1-smtp.messagingengine.com|<adam.w...@koparo.com>|<adam.w...@tintagel.pl>|1430142855|1430145035|1430157255|4|0
>
>
> > - todd
> >
>
> The weird thing is - it just started happening. I did see other weird
> issues
> like spamdb not showing any entries in short periods of time but I
> assumed
> that it was expired hosts and they always came back after a while.
>
> I did make a copy of my /var/db/spamd in case it's a corrupt db. Though
> nothing
> specific was happening with the host when the errors started.
>
> I started looking at /usr/src which makes me think the issue comes from:
>
> /usr/src/libexec/spamd/grey.c
> case DBC_DEL:
> memset(&dbk, 0, sizeof(dbk));
> dbk.size = strlen(dbc->key);
> dbk.data = dbc->key;
> if (db->del(db, &dbk, 0)) {
> syslog_r(LOG_ERR, &sdata,
> "can't delete %s from spamd db
> (%m)",
> dbc->key);
> ret = -1;
> }
> break;
>
> which uses the hash version of db.h
> /usr/src/lib/libc/db/hash/hash.c
>
> hash_delete(const DB *dbp, const DBT *key,
> u_int32_t flag) /* Ignored */
> {
> HTAB *hashp;
>
> hashp = (HTAB *)dbp->internal;
> if (flag && flag != R_CURSOR) {
> hashp->err = errno = EINVAL;
> return (ERROR);
> }
> if ((hashp->flags & O_ACCMODE) == O_RDONLY) {
> hashp->err = errno = EPERM;
> return (ERROR);
> }
> return (hash_access(hashp, HASH_DELETE, (DBT *)key, NULL));
> }
>
> The line with EINVAL like you correctly pointed out.
> While here, why is flag marked as /* ignored */ and the error I'm
> hitting looks like code which verifies if that parameter was properly
> set?
>
> The if shouldn't have a way to trigger since del is passed 0 as the flag
> parameter so I'm a bit dumbfounded here. I couldn't find any other
> part of the code that could result in the exact same error message.
>
> I am trying to write a small C program to open the db file to try and
> delete
> the entry from a reduced use case - so far it's being going really slow
> to get
> a useful test case. Not sure if I will be able to whip it up in a
> reasonable time frame.
>
> Regards,
> Adam
