12.11.2011 04:20, Gary V yazmış:
2011/11/11 Müfit Eribol
Hello All,
I have installed razor2, pyzor, DCC, spamassassin and amavisd-new.
But, I
doubt razor2 is working. Below is the debug of razor2 run. But it
times out
after 5 seconds. I have no idea about how to solve. Firewall is
disabled on
the machine. However, there is NAT on the internet gateway. Perhaps
a port
needs to be opened and routed to this machine on the gateway for the
incoming packets.
I would appreciate any insight.
All the best,
Mufit
[root@mail log]# spamassassin -t -D razor2 <
/usr/share/doc/spamassassin-3.3.1/sample-spam.txt
Nov 8 23:13:44.774 [5235] dbg: razor2: razor2 is available, version
2.84
Razor-Log: read_file: 16 items read from
/var/spool/amavisd/.razor/razor-agent.conf
Razor-Log: Found razorhome: /var/spool/amavisd/.razor
Nov 08 23:14:15.725569 check[5235]: [ 2] [bootup] Logging initiated
LogDebugLevel=9 to stdout
Nov 08 23:14:15.725801 check[5235]: [ 5] computed
razorhome=/var/spool/amavisd/.razor,
conf=/var/spool/amavisd/.razor/razor-agent.conf,
ident=/var/spool/amavisd/.razor/identity-ruNzHkARhN
Nov 08 23:14:15.726067 check[5235]: [ 8] Client supported_engines: 4
8
Nov 08 23:14:15.726329 check[5235]: [ 8] prep_mail done: mail 1
headers=293, mime0=616
Nov 08 23:14:15.726519 check[5235]: [ 5] read_file: 1 items read
from
/var/spool/amavisd/.razor/servers.discovery.lst
Nov 08 23:14:15.726686 check[5235]: [ 5] read_file: 4 items read
from
/var/spool/amavisd/.razor/servers.nomination.lst
Nov 08 23:14:15.726861 check[5235]: [ 5] read_file: 3 items read
from
/var/spool/amavisd/.razor/servers.catalogue.lst
Nov 08 23:14:15.727163 check[5235]: [ 9] Assigning defaults to
n001.cloudmark.com
Nov 08 23:14:15.727232 check[5235]: [ 9] Assigning defaults to
n004.cloudmark.com
Nov 08 23:14:15.727310 check[5235]: [ 9] Assigning defaults to
n003.cloudmark.com
Nov 08 23:14:15.727386 check[5235]: [ 9] Assigning defaults to
n002.cloudmark.com
Nov 08 23:14:15.727490 check[5235]: [ 9] Assigning defaults to
c303.cloudmark.com
Nov 08 23:14:15.727584 check[5235]: [ 9] Assigning defaults to
c302.cloudmark.com
Nov 08 23:14:15.727663 check[5235]: [ 9] Assigning defaults to
c301.cloudmark.com
Nov 08 23:14:15.728293 check[5235]: [ 5] read_file: 31 items read
from
/var/spool/amavisd/.razor/server.c303.cloudmark.com.conf
Nov 08 23:14:15.728660 check[5235]: [ 5] read_file: 31 items read
from
/var/spool/amavisd/.razor/server.c303.cloudmark.com.conf
Nov 08 23:14:15.729113 check[5235]: [ 5] read_file: 31 items read
from
/var/spool/amavisd/.razor/server.c302.cloudmark.com.conf
Nov 08 23:14:15.729460 check[5235]: [ 5] read_file: 31 items read
from
/var/spool/amavisd/.razor/server.c302.cloudmark.com.conf
Nov 08 23:14:15.729774 check[5235]: [ 5] read_file: 28 items read
from
/var/spool/amavisd/.razor/server.n001.cloudmark.com.conf
Nov 08 23:14:15.730202 check[5235]: [ 5] read_file: 28 items read
from
/var/spool/amavisd/.razor/server.n001.cloudmark.com.conf
Nov 08 23:14:15.730558 check[5235]: [ 5] read_file: 31 items read
from
/var/spool/amavisd/.razor/server.c301.cloudmark.com.conf
Nov 08 23:14:15.730873 check[5235]: [ 5] read_file: 31 items read
from
/var/spool/amavisd/.razor/server.c301.cloudmark.com.conf
Nov 08 23:14:15.731119 check[5235]: [ 5] server discovery overdue by
160953
seconds
Nov 08 23:14:15.731175 check[5235]: [ 8] already have 1 discovery
servers
Nov 08 23:14:15.731216 check[5235]: [ 8] Checking with Razor
Discovery
Server discovery.razor.cloudmark.com
Nov 08 23:14:15.731296 check[5235]: [ 6] No port specified, using
2703
Nov 08 23:14:15.731331 check[5235]: [ 5] Connecting to
discovery.razor.cloudmark.com ...
Nov 8 23:14:20.788 [5235] dbg: razor2: razor2 check timed out after
5
seconds
Nov 8 23:14:20.789 [5235] dbg: razor2: results: spam? 0
Nov 8 23:14:20.789 [5235] dbg: razor2: results: engine 8, highest
cf score:
0
Nov 8 23:14:20.789 [5235] dbg: razor2: results: engine 4, highest
cf score:
0
Try running the debug command as your amavis user, for example:
su amavis -c 'spamassassin -t -D razor2 <
/usr/share/doc/spamassassin-3.3.1/sample-spam.txt'
If the result is no different, then you could try re-registering and
re-discovering and running the debug command as your amavis user
again.
su amavis -c 'razor-admin -register'
su amavis -c 'razor-admin -discover'
su amavis -c 'spamassassin -t -D razor2 <
/usr/share/doc/spamassassin-3.3.1/sample-spam.txt'
BTW, the sample spam does not appear to trigger a razor2 hit, but
that
is not the issue here.
Thank you for your support.
I did the check with "su amavis -c" as you suggested. The result is the
same as above. All files are owned by amavis /var/spool/amavisd
including directory .razor.
However, if we take spamassassin out of the equation (Kevin A.
McGrail's suggestion), result is different:
[root@mail ~]# razor-check -d <
/usr/share/doc/spamassassin-3.3.1/sample-spam.txt
Razor-Log: Computed razorhome from env: /root/.razor
Razor-Log: Found razorhome: /root/.razor
Razor-Log: No /root/.razor/razor-agent.conf found, skipping.
Razor-Log: No razor-agent.conf found, using defaults.
Nov 12 17:25:24.294927 check[3162]: [ 2] [bootup] Logging initiated
LogDebugLevel=9 to stdout
Nov 12 17:25:24.295113 check[3162]: [ 5] computed
razorhome=/root/.razor, conf=, ident=/root/.razor/identity
Nov 12 17:25:24.295164 check[3162]: [ 2] Razor-Agents v2.84 starting
razor-check -d
Nov 12 17:25:24.295447 check[3162]: [ 8] reading straight RFC822 mail
from <stdin>
Nov 12 17:25:24.295543 check[3162]: [ 6] read 1 mail
Nov 12 17:25:24.295620 check[3162]: [ 8] Client supported_engines: 4 8
Nov 12 17:25:24.295850 check[3162]: [ 8] prep_mail done: mail 1
headers=293, mime0=616
Nov 12 17:25:24.295925 check[3162]: [ 6] skipping whitelist file
(empty?): /root/.razor/razor-whitelist
Nov 12 17:25:24.296034 check[3162]: [ 5] read_file: 1 items read from
/root/.razor/servers.discovery.lst
Nov 12 17:25:24.296159 check[3162]: [ 5] read_file: 4 items read from
/root/.razor/servers.nomination.lst
Nov 12 17:25:24.296414 check[3162]: [ 5] read_file: 3 items read from
/root/.razor/servers.catalogue.lst
Nov 12 17:25:24.296580 check[3162]: [ 9] Assigning defaults to
n002.cloudmark.com
Nov 12 17:25:24.296656 check[3162]: [ 9] Assigning defaults to
n001.cloudmark.com
Nov 12 17:25:24.296714 check[3162]: [ 9] Assigning defaults to
n004.cloudmark.com
Nov 12 17:25:24.296795 check[3162]: [ 9] Assigning defaults to
n003.cloudmark.com
Nov 12 17:25:24.296858 check[3162]: [ 9] Assigning defaults to
c302.cloudmark.com
Nov 12 17:25:24.296913 check[3162]: [ 9] Assigning defaults to
c301.cloudmark.com
Nov 12 17:25:24.296975 check[3162]: [ 9] Assigning defaults to
c303.cloudmark.com
Nov 12 17:25:24.297473 check[3162]: [ 5] read_file: 31 items read from
/root/.razor/server.c303.cloudmark.com.conf
Nov 12 17:25:24.297789 check[3162]: [ 5] read_file: 31 items read from
/root/.razor/server.c303.cloudmark.com.conf
Nov 12 17:25:24.298042 check[3162]: [ 5] read_file: 31 items read from
/root/.razor/server.c302.cloudmark.com.conf
Nov 12 17:25:24.298430 check[3162]: [ 5] read_file: 31 items read from
/root/.razor/server.c302.cloudmark.com.conf
Nov 12 17:25:24.298735 check[3162]: [ 5] read_file: 31 items read from
/root/.razor/server.c301.cloudmark.com.conf
Nov 12 17:25:24.298980 check[3162]: [ 5] read_file: 31 items read from
/root/.razor/server.c301.cloudmark.com.conf
Nov 12 17:25:24.299059 check[3162]: [ 5] 170082 seconds before closest
server discovery
Nov 12 17:25:24.299131 check[3162]: [ 6] c302.cloudmark.com is a
Catalogue Server srl 13872; computed min_cf=21, Server se: 23C0
Nov 12 17:25:24.299195 check[3162]: [ 8] Computed supported_engines: 8
Nov 12 17:25:24.299372 check[3162]: [ 8] Using next closest server
c302.cloudmark.com:2703, cached info srl 13872
Nov 12 17:25:24.299418 check[3162]: [ 8] mail 1 has no subject
Nov 12 17:25:24.299544 check[3162]: [ 6] preproc: mail 1.0 went from
616 bytes to 503
Nov 12 17:25:24.299606 check[3162]: [ 6] computing sigs for mail 1.0,
len 503
Nov 12 17:25:24.300011 check[3162]: [ 6] Engine (8) didn't produce a
signature for mail 1.0
Nov 12 17:25:24.300081 check[3162]: [ 5] 166669 seconds before closest
server discovery
Nov 12 17:25:24.300133 check[3162]: [ 6] c301.cloudmark.com is a
Catalogue Server srl 13860; computed min_cf=21, Server se: 23C0
Nov 12 17:25:24.300190 check[3162]: [ 8] Computed supported_engines: 8
Nov 12 17:25:24.300361 check[3162]: [ 8] Using next closest server
c301.cloudmark.com:2703, cached info srl 13860
Nov 12 17:25:24.300424 check[3162]: [ 5] Connecting to
c301.cloudmark.com ...
Nov 12 17:25:29.725136 check[3162]: [ 8] Connection established
Nov 12 17:25:29.725358 check[3162]: [ 4] c301.cloudmark.com >> 37
server greeting: sn=C&srl=13872&a=1&a=cg&ep4=7542-10
Nov 12 17:25:29.725499 check[3162]: [ 4] c301.cloudmark.com << 25
Nov 12 17:25:29.725533 check[3162]: [ 6] cn=razor-agents&cv=2.84
Nov 12 17:25:29.725661 check[3162]: [ 4] c301.cloudmark.com << 14
Nov 12 17:25:29.725703 check[3162]: [ 6] a=g&pm=state
Nov 12 17:25:30.099558 check[3162]: [ 4] c301.cloudmark.com >> 281
Nov 12 17:25:30.099641 check[3162]: [ 6] response to sent.2
-sn=C
sv=3.102
zone=razor2.cloudmark.com
ac=21
srl=13872
lm=4
bql=50
bqs=257
dre=4
srf=FF
sa=2FB
se=23C0
to=15
ep4=7542-10
ep8=20
ep10=5
ep16=5
ep19=5
ep20=5
ep21=5
crt=90
immdi=1
imsio=0
lsp=3
lsp10=0
mps=128
mhs=15
mphs=4
cp=7 1 6 5 4 3 2 0
cs=1
.
Nov 12 17:25:30.100413 check[3162]: [ 5] Updated to new server state
srl 13872 for server c301.cloudmark.com
Nov 12 17:25:30.100491 check[3162]: [ 6] c301.cloudmark.com is a
Catalogue Server srl 13872; computed min_cf=21, Server se: 23C0
Nov 12 17:25:30.100585 check[3162]: [ 8] Computed supported_engines: 8
Nov 12 17:25:30.100991 check[3162]: [ 5] wrote 31 HASH items to file:
/root/.razor/server.c301.cloudmark.com.conf
Nov 12 17:25:30.101045 check[3162]: [ 5] srl was updated, forcing
discovery ...
Nov 12 17:25:30.101118 check[3162]: [ 5] 155494 seconds before closest
server discovery
Nov 12 17:25:30.101157 check[3162]: [ 5] forcing discovery
Nov 12 17:25:30.101399 check[3162]: [ 8] already have 1 discovery
servers
Nov 12 17:25:30.101459 check[3162]: [ 8] Checking with Razor Discovery
Server discovery.razor.cloudmark.com
Nov 12 17:25:30.101533 check[3162]: [ 6] losing old server connection,
c301.cloudmark.com, for new server, discovery.razor.cloudmark.com
Nov 12 17:25:30.101580 check[3162]: [ 5] disconnecting from server
c301.cloudmark.com
Nov 12 17:25:30.101660 check[3162]: [ 4] c301.cloudmark.com << 5
Nov 12 17:25:30.101905 check[3162]: [ 6] a=q
Nov 12 17:25:30.102003 check[3162]: [ 5] Connecting to
discovery.razor.cloudmark.com ...
Nov 12 17:25:35.496519 check[3162]: [ 8] Connection established
Nov 12 17:25:35.496651 check[3162]: [ 4] discovery.razor.cloudmark.com
>> 35 server greeting: sn=D&srl=596&a=1&a=cg&ep4=7542-10
Nov 12 17:25:35.496728 check[3162]: [ 4] discovery.razor.cloudmark.com
<< 12
Nov 12 17:25:35.496760 check[3162]: [ 6] a=g&pm=csl
Nov 12 17:25:35.667399 check[3162]: [ 4] discovery.razor.cloudmark.com
>> 71
Nov 12 17:25:35.667463 check[3162]: [ 6] response to sent.4
-csl=?
c302.cloudmark.com
c303.cloudmark.com
c301.cloudmark.com
.
Nov 12 17:25:35.667545 check[3162]: [ 8] Discovery Server
discovery.razor.cloudmark.com replying with csl=c302.cloudmark.com
Nov 12 17:25:35.667576 check[3162]: [ 8] Discovery Server
discovery.razor.cloudmark.com replying with csl=c303.cloudmark.com
Nov 12 17:25:35.667603 check[3162]: [ 8] Discovery Server
discovery.razor.cloudmark.com replying with csl=c301.cloudmark.com
Nov 12 17:25:35.667697 check[3162]: [ 4] discovery.razor.cloudmark.com
<< 12
Nov 12 17:25:35.667728 check[3162]: [ 6] a=g&pm=nsl
Nov 12 17:25:35.837587 check[3162]: [ 4] discovery.razor.cloudmark.com
>> 91
Nov 12 17:25:35.837667 check[3162]: [ 6] response to sent.5
-nsl=?
n001.cloudmark.com
n003.cloudmark.com
n004.cloudmark.com
n002.cloudmark.com
.
Nov 12 17:25:35.837755 check[3162]: [ 8] Discovery Server
discovery.razor.cloudmark.com replying with nsl=n001.cloudmark.com
Nov 12 17:25:35.837807 check[3162]: [ 8] Discovery Server
discovery.razor.cloudmark.com replying with nsl=n003.cloudmark.com
Nov 12 17:25:35.837838 check[3162]: [ 8] Discovery Server
discovery.razor.cloudmark.com replying with nsl=n004.cloudmark.com
Nov 12 17:25:35.837865 check[3162]: [ 8] Discovery Server
discovery.razor.cloudmark.com replying with nsl=n002.cloudmark.com
Nov 12 17:25:35.837934 check[3162]: [ 5] disconnecting from server
discovery.razor.cloudmark.com
Nov 12 17:25:35.837995 check[3162]: [ 4] discovery.razor.cloudmark.com
<< 5
Nov 12 17:25:35.838024 check[3162]: [ 6] a=q
Nov 12 17:25:35.838541 check[3162]: [ 5] wrote 3 ARRAY items to file:
/root/.razor/servers.catalogue.lst
Nov 12 17:25:35.838718 check[3162]: [ 5] wrote 4 ARRAY items to file:
/root/.razor/servers.nomination.lst
Nov 12 17:25:35.838847 check[3162]: [ 5] mail 1.0 e8 got no sig
Nov 12 17:25:35.838885 check[3162]: [ 5] No queries, no spam
Nov 12 17:25:35.838914 check[3162]: [ 5] already disconnected from
server discovery.razor.cloudmark.com
Nov 12 17:25:35.838957 check[3162]: [ 8] razor-check finished
successfully.
So, how should we interpret the results? Looks like spamassassin does
not play well with razor2 for a reason. Perhaps a configuration issue?
Regards,
Mufit Eribol
