>Run with debugging on, send the problem emails through again, and see if
>something shows up.
Ok, this is a good suggestion. Looking at the clamav-milter man page
I see two different debug flag, --debug and --debug-level. I randomly
picked the latter, and tried running with --debug-level=9. This flag
was not recognized, of course, since the FreeBSD port isn't compiled
with debugging enabled. I hacked the port's Makefile to add this,
rebuilt & reinstalled, and then ran.
What I find in the syslog is a whole bunch of debug log entries,
from every time a milter routine gets called. However what I don't
see is any way to correlate which log entries belong to which mail
sessions. That makes them less useful than they should be. What
I do when I'm debugging my milters is give each connection a unique
i.d. number, and put that in all the syslogs.
Anyway, I picked a false-positive from my non-clamavs folder and
looked for it in the mail log. I was able to find the initial
connection, and the final disposition, with an elapsed time of 30
seconds between them. During those 30 seconds there were 3283 other
mail syslogs. If I eliminate all but clamav-related logs, there
were only 805. About 740 of those were clamfi_connect entries for
other connections, so I could get rid of those. Most of the rest
were also from other connections, and I could get rid of them one
by one.
After this winnowing process, the only syslogs left between the
initial connection and the final disposition were 16 connect2clamd
lines. Presumably one of the 16 was for the connection I was
interested in and the others were for other connections. There
were no syslogs for any other clamfi calls whatsoever. So that
was a big bust, unless you can infer something from negative evidence.
Anyway, the results are below.
Afterwards I stopped and restarted clamav-milter without the
--debug-level flag. Guess what, it still generates debug info
on stdout. I guess that is why the FreeBSD port does not enable
debugging.
---
Jef
Jef Poskanzer [EMAIL PROTECTED] http://www.acme.com/jef/
May 17 16:34:34 gate sm-mta[49779]: NOQUEUE: connect from [220.248.104.130]
May 17 16:34:34 gate clamav-milter[11373]: clamfi_connect: connection from
220.248.104.130
May 17 16:34:40 gate clamav-milter[11373]: connect2clamd
May 17 16:34:40 gate clamav-milter[11373]: connect2clamd
May 17 16:34:42 gate clamav-milter[11373]: connect2clamd
May 17 16:34:46 gate clamav-milter[11373]: connect2clamd
May 17 16:34:46 gate clamav-milter[11373]: connect2clamd
May 17 16:34:49 gate clamav-milter[11373]: connect2clamd
May 17 16:34:50 gate clamav-milter[11373]: connect2clamd
May 17 16:34:52 gate clamav-milter[11373]: connect2clamd
May 17 16:34:52 gate clamav-milter[11373]: connect2clamd
May 17 16:34:53 gate clamav-milter[11373]: connect2clamd
May 17 16:34:54 gate clamav-milter[11373]: connect2clamd
May 17 16:34:56 gate clamav-milter[11373]: connect2clamd
May 17 16:35:01 gate clamav-milter[11373]: connect2clamd
May 17 16:35:02 gate clamav-milter[11373]: connect2clamd
May 17 16:35:03 gate clamav-milter[11373]: connect2clamd
May 17 16:35:04 gate clamav-milter[11373]: connect2clamd
May 17 16:35:04 gate sm-mta[49779]: j4HNYYJY049779: [EMAIL PROTECTED],
size=204868, class=0, nrcpts=1, msgid=<[EMAIL PROTECTED]>, bodytype=8BITMIME,
proto=ESMTP, daemon=MTA, relay=[220.248.104.130]
May 17 16:35:04 gate clamav-milter[11373]: j4HNYYJY049779: clean message from
[EMAIL PROTECTED]
May 17 16:35:04 gate sm-mta[53666]: j4HNYYJY049779: forward [EMAIL PROTECTED]
=> "|/usr/local/bin/procmail #jef"
May 17 16:35:04 gate sm-mta[53666]: j4HNYYJY049779:
to="|/usr/local/bin/procmail #jef", [EMAIL PROTECTED] (1544/1002),
delay=00:00:16, xdelay=00:00:00, mailer=prog, pri=235496, dsn=2.0.0, stat=Sent
May 17 16:35:04 gate sm-mta[53666]: j4HNYYJY049779: done; delay=00:00:16,
ntries=1
May 17 16:35:04 gate jef: filtered: non-ClamAV worm
_______________________________________________
http://lurker.clamav.net/list/clamav-users.html
