Troubleshooting

mx0:~# ps ax | grep ze-filter
23062 ?        S      0:00 /usr/sbin/ze-filter
23063 ?        Sl   325:36 /usr/sbin/ze-filter

Usually, syslog file is /var/log/ze-filter. We can see that in /etc/syslog.conf

local5.debug -/var/log/ze-filter

Don't forget to put an hyphen in front of file name as it indicated to use asynchronous write. Without it, the filter will have difficulties to work.

Have a look at it:

Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.info] 47C7D609.002 Bayes filter score :  0.015
Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.notice] 47C7D609.002 SPAM CHECK - H06 HTML tag/text ratio : 1
Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.info] 47C7D609.002 ORACLE - H06 HTML tag/text ratio (   0.5)
Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.info] 47C7D60C.001 Bayes filter score :  0.621
Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.notice] 47C7D60C.001 SPAM CHECK - P04 text/plain part too short : 31
Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.notice] 47C7D60C.001 DBURLBL : yq.ranglad.com :  20 BLACKLISTED in DBURLBL:multi.surbl
Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.info] 47C7D60C.001 ORACLE - P04 text/plain too short (   0.0)
Feb 29 10:53:17 mx0 ze-filter[23063]: [ID 000000 local5.notice] 47C7D60C.001 : SMQID=(NOID), Callback=(eom), Why=(Content Check : B=0.621 U=20 R=0 O=0 -> G=1.036), PeerAddr=(XX), PeerName=(XXX), MAIL=(<bgates@traducegratis.com>), NbRCPT=(1/1), RCPT=(<YY@XX>), HeaderFrom=(<bgates@traducegratis.com>), Mailer=(Thunderbird 2.0.0.6 (Windows/20070728)), Scores=(R=0 U=20 O=0 B=0.621 ->  1.036), Size=(44), Reply=(550 5.7.1 Sorry, this message is being rejected as it seems to be a spam !)

We can see jchmail working and rejecting SPAM

We can use the ze-ndc command to see that: For example

mx0:~# ze-printstats -a
Loading ze-filter configuration
Loading default values
Reading configuration file : /etc/ze-filter/ze-filter.cf
Reloading configuration tables...
Version                        : Joe's ze-filter v1.12.0-080224
Last counters dump             : Fri Feb 29 11:29:17 2008

*** PROCESSUS DATA ***         Tue Feb 26 20:26:22 2008
*** GLOBAL DATA ***            Wed Jun 13 11:33:37 2007
# Start-up                                 :          1         139
# Messages                                 :      51432     1625466
# KBytes                                   :    6088965   200943075
# Connect                                  :     274790     8686526
....

If we look at line startup, we can see two columns. The first shows counter from Tue Feb 26 20:26:22 2008, the second from Wed Jun 13 11:33:37 2007 (the very first try with ze-filter on that server)

We can say that for 3 days, the filter was not internally restarted. A restart is an indication that something went wrong, you should see the restart in the syslog

First, find the right process (there is two processes)

mx0:~/jchkze-filter-1.12.0-080204/src# ps -m -u smmsp
  PID TTY          TIME CMD
23062 ?        00:00:00 ze-filter
    - -        00:00:00 -
 7771 ?        00:00:12 ze-filter
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -
    - -        00:00:00 -

We can see that the filter process number, is 7771 as it is launching pool or thread. We can attach it using gdb:

gdb -p 7771

(gdb) info thread
  12 Thread -1219789904 (LWP 7772)  0xb7eb268c in nanosleep () from /lib/tls/libc.so.6
  11 Thread -1228178512 (LWP 7773)  0xb7eb268c in nanosleep () from /lib/tls/libc.so.6
  10 Thread -1236567120 (LWP 7774)  0xb7e4ceb9 in sigsuspend () from /lib/tls/libc.so.6
  9 Thread -1244955728 (LWP 7775)  0xb7ef0aee in accept () from /lib/tls/libc.so.6
  8 Thread -1265161296 (LWP 7776)  0xb7eb268c in nanosleep () from /lib/tls/libc.so.6
  7 Thread -1273549904 (LWP 7777)  0xb7eb268c in nanosleep () from /lib/tls/libc.so.6
  6 Thread -1283339344 (LWP 7782)  0xb7eb268c in nanosleep () from /lib/tls/libc.so.6
  5 Thread -1291887696 (LWP 7783)  0xb7e4ceb9 in sigsuspend () from /lib/tls/libc.so.6
  4 Thread -1300276304 (LWP 7784)  0xb7ee6529 in poll () from /lib/tls/libc.so.6
  3 Thread -1547699280 (LWP 8175)  0xb7df0e62 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/tls/libpthread.so.0
  2 Thread -1317053520 (LWP 8192)  0xb7df0e62 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/tls/libpthread.so.0
  1 Thread -1210157376 (LWP 7771)  0xb7ee6529 in poll () from /lib/tls/libc.so.6
(gdb)

We can see that they are all waiting on system call. If one of them was looping we would be able to see in what part of code.

Quarantine can be usefull to examine what happens (xfiles, spam). Activate it in ze-filter.cf or via “ze-ndc setcf XFILE_SAVE_MSG YES” or XSTATUS_QUARANTINE_CONDITION and have a look in /var/spool/ze-filter