Version: 3.0.1 (via FreeBSD Ports)
Invokation: /usr/local/bin/spamd -d -q -x -r /var/run/spamd.pid (perl) (via sa-exim (via FreeBSD Ports)) (exim 4.43 (via FreeBSD Ports))
(note: @ replaced with -at- for email addresses for purposes of sanitizing this message)
I've got spamd pulling prefs out of mysql.
The mysql values for my email address are:
mysql> select * from spamassassin.userpref;
+-------------------------+---------------- +----------------------------+--------+
| username | preference | value | prefid |
+-------------------------+---------------- +----------------------------+--------+
| $GLOBAL | required_hits | 5.0 | 1 |
| jason-at-lixfeld.ca | whitelist_from | plixfeld-at-andromedas.com | 3 |
| jason.lixfeld.ca | whitelist_from | plixfeld-at-andromedas.com | 4 |
+-------------------------+---------------- +----------------------------+--------+
4 rows in set (0.00 sec)
-jason.lixfeld.ca is the system user name. jason-at-lixfeld.ca is an alias which points to jason.lixfeld.ca. I put both in because I wasn't sure if it was checking against the rcpt to: address or recipient's system user name.
-Spamd's logfile below shows the from plixfeld-at-andromedas.com to jason-at-lixfeld.ca. The system things the username is "nobody". I've tried with both the -q and -Q spamd switches to no avail.
-anyone know what's going on here?
=== 8< ===
logmsg: connection from localhost [127.0.0.1] at port 57943
debug: Conf::SQL: executing SQL: SELECT preference, value FROM userpref WHERE username = 'nobody' OR username = '$GLOBAL' OR username = CONCAT('%',NULL) ORDER BY username ASC
debug: retrieving prefs for nobody from SQL server
debug: user has changed
debug: bayes: 95675 tie-ing to DB file R/O /root/.spamassassin/bayes_toks
debug: bayes: 95675 tie-ing to DB file R/O /root/.spamassassin/bayes_seen
debug: bayes: found bayes db version 3
debug: bayes: Not available for scanning, only 14 spam(s) in Bayes DB < 200
debug: bayes: 95675 untie-ing
debug: bayes: 95675 untie-ing db_toks
debug: bayes: 95675 untie-ing db_seen
debug: Score set 1 chosen.
logmsg: checking message (unknown) for nobody:0.
debug: bayes: 95675 tie-ing to DB file R/O /root/.spamassassin/bayes_toks
debug: bayes: 95675 tie-ing to DB file R/O /root/.spamassassin/bayes_seen
debug: bayes: found bayes db version 3
debug: bayes: Not available for scanning, only 14 spam(s) in Bayes DB < 200
debug: bayes: 95675 untie-ing
debug: bayes: 95675 untie-ing db_toks
debug: bayes: 95675 untie-ing db_seen
debug: received-header: parsed as [ ip=216.7.194.254 rdns=trek.lixfeld.ca helo=foo.com by=eshara.ebit.ca ident= envfrom= intl=0 id=1CNRrL-000Oti-Ks ]
debug: is Net::DNS::Resolver available? yes
debug: Net::DNS version: 0.48
debug: looking up A records for 'eshara.ebit.ca'
debug: A records for 'eshara.ebit.ca': 69.90.17.218
debug: looking up A records for 'eshara.ebit.ca'
debug: A records for 'eshara.ebit.ca': 69.90.17.218
debug: received-header: 'by' eshara.ebit.ca has public IP 69.90.17.218
debug: received-header: relay 216.7.194.254 trusted? no internal? no
debug: metadata: X-Spam-Relays-Trusted:
debug: metadata: X-Spam-Relays-Untrusted: [ ip=216.7.194.254 rdns=trek.lixfeld.ca helo=foo.com by=eshara.ebit.ca ident= envfrom= intl=0 id=1CNRrL-000Oti-Ks ]
debug: ---- MIME PARSER START ----
debug: main message type: text/plain
debug: parsing normal part
debug: added part, type: text/plain
debug: ---- MIME PARSER END ----
debug: decoding: no encoding detected
debug: Message too short for language analysis
debug: is Net::DNS::Resolver available? yes
debug: Net::DNS version: 0.48
debug: all '*From' addrs:
debug: Running tests for priority: 0
debug: running header regexp tests; score so far=0
debug: all '*To' addrs: jason-at-lixfeld.ca
debug: forged-HELO: from=trek.lixfeld.ca helo=foo.com by=eshara.ebit.ca
debug: forged-HELO: mismatch on HELO: 'foo.com' != 'trek.lixfeld.ca'
debug: running body-text per-line regexp tests; score so far=0.069
debug: running uri tests; score so far=0.069
debug: Razor2 is available
debug: entering helper-app run mode
Razor-Log: Computed razorhome from env: /root/.razor
Razor-Log: No razorhome found, using all defaults
Razor-Log: No razor-agent.conf found, using defaults.
Oct 29 04:12:01.427177 check[95675]: [ 2] [bootup] Logging initiated LogDebugLevel=9 to stdout
Oct 29 04:12:01.427377 check[95675]: [ 5] computed razorhome=, conf=, ident=identity
Oct 29 04:12:01.427519 check[95675]: [ 8] Client supported_engines: 4 8
Oct 29 04:12:01.427793 check[95675]: [ 8] prep_mail done: mail 1 headers=189, mime0=40
Oct 29 04:12:01.427953 check[95675]: [ 7] Can't read file servers.discovery.lst, looking relatve to
Oct 29 04:12:01.428064 check[95675]: [ 5] Can't read file /servers.discovery.lst: No such file or directory
Oct 29 04:12:01.428166 check[95675]: [ 7] Can't read file servers.nomination.lst, looking relatve to
Oct 29 04:12:01.428264 check[95675]: [ 5] Can't read file /servers.nomination.lst: No such file or directory
Oct 29 04:12:01.428364 check[95675]: [ 7] Can't read file servers.catalogue.lst, looking relatve to
Oct 29 04:12:01.428462 check[95675]: [ 5] Can't read file /servers.catalogue.lst: No such file or directory
Oct 29 04:12:01.428619 check[95675]: [ 5] no listfile: servers.catalogue.lst
Oct 29 04:12:01.428732 check[95675]: [ 6] no discovery listfile: servers.discovery.lst
Oct 29 04:12:01.428820 check[95675]: [ 5] Finding Discovery Servers via DNS in the razor2.cloudmark.com zone
Oct 29 04:12:01.432602 check[95675]: [ 6] Found 1 Discovery Servers via DNS in the razor2.cloudmark.com zone
Oct 29 04:12:01.432795 check[95675]: [ 8] Checking with Razor Discovery Server 66.151.150.12
Oct 29 04:12:01.432915 check[95675]: [ 6] No port specified, using 2703
Oct 29 04:12:01.433002 check[95675]: [ 5] Connecting to 66.151.150.12 ...
Oct 29 04:12:01.549760 check[95675]: [ 8] Connection established
Oct 29 04:12:01.549893 check[95675]: [ 4] 66.151.150.12 >> 35 server greeting: sn=D&srl=460&a=l&a=cg&ep4=7542-10
Oct 29 04:12:01.550149 check[95675]: [ 4] 66.151.150.12 << 12
Oct 29 04:12:01.550245 check[95675]: [ 6] a=g&pm=csl
Oct 29 04:12:01.610629 check[95675]: [ 4] 66.151.150.12 >> 76
Oct 29 04:12:01.610732 check[95675]: [ 6] response to sent.1
-csl=?
wonder.cloudmark.com
pride.cloudmark.com
thrill.cloudmark.com
.
Oct 29 04:12:01.610930 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with csl=wonder.cloudmark.com
Oct 29 04:12:01.610978 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with csl=pride.cloudmark.com
Oct 29 04:12:01.611021 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with csl=thrill.cloudmark.com
Oct 29 04:12:01.611173 check[95675]: [ 4] 66.151.150.12 << 12
Oct 29 04:12:01.611214 check[95675]: [ 6] a=g&pm=nsl
Oct 29 04:12:01.670885 check[95675]: [ 4] 66.151.150.12 >> 51
Oct 29 04:12:01.670986 check[95675]: [ 6] response to sent.2
-nsl=?
joy.cloudmark.com
folly.cloudmark.com
.
Oct 29 04:12:01.671166 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with nsl=joy.cloudmark.com
Oct 29 04:12:01.671213 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with nsl=folly.cloudmark.com
Oct 29 04:12:01.671338 check[95675]: [ 5] no razorhome, not caching server info to disk
Oct 29 04:12:01.671426 check[95675]: [ 6] losing old server connection, 66.151.150.12, for new server, thrill.cloudmark.com
Oct 29 04:12:01.671474 check[95675]: [ 5] disconnecting from server 66.151.150.12
Oct 29 04:12:01.671617 check[95675]: [ 4] 66.151.150.12 << 5
Oct 29 04:12:01.671657 check[95675]: [ 6] a=q
Oct 29 04:12:01.671724 check[95675]: [ 5] Connecting to thrill.cloudmark.com ...
Oct 29 04:12:01.788480 check[95675]: [ 8] Connection established
Oct 29 04:12:01.788749 check[95675]: [ 4] thrill.cloudmark.com >> 36 server greeting: sn=C&srl=5047&a=l&a=cg&ep4=7542-10
Oct 29 04:12:01.789122 check[95675]: [ 4] thrill.cloudmark.com << 25
Oct 29 04:12:01.789220 check[95675]: [ 6] cn=razor-agents&cv=2.61
Oct 29 04:12:01.789490 check[95675]: [ 4] thrill.cloudmark.com << 14
Oct 29 04:12:01.789593 check[95675]: [ 6] a=g&pm=state
Oct 29 04:12:01.906236 check[95675]: [ 4] thrill.cloudmark.com >> 141
Oct 29 04:12:01.906339 check[95675]: [ 6] response to sent.5
-sv=3.44
sn=C
zone=razor2.cloudmark.com
ac=6
srl=5047
lm=4
bql=50
bqs=129
dre=4
se=C8
srf=FF
ep4=7542-10
ep8=5
pp=1
crt=90
.
Oct 29 04:12:01.907103 check[95675]: [ 5] Updated to new server state srl 5047 for server thrill.cloudmark.com
Oct 29 04:12:01.907261 check[95675]: [ 6] thrill.cloudmark.com is a Catalogue Server srl 5047; computed min_cf=6, Server se: C8
Oct 29 04:12:01.907415 check[95675]: [ 8] Computed supported_engines: 4 8
Oct 29 04:12:01.907470 check[95675]: [ 5] no razorhome, not caching server info to disk
Oct 29 04:12:01.907510 check[95675]: [ 5] srl was updated, forcing discovery ...
Oct 29 04:12:01.907590 check[95675]: [ 5] no listfile: servers.catalogue.lst
Oct 29 04:12:01.907649 check[95675]: [ 8] already have 1 discovery servers
Oct 29 04:12:01.907700 check[95675]: [ 8] Checking with Razor Discovery Server 66.151.150.12
Oct 29 04:12:01.907759 check[95675]: [ 6] losing old server connection, thrill.cloudmark.com, for new server, 66.151.150.12
Oct 29 04:12:01.907803 check[95675]: [ 5] disconnecting from server thrill.cloudmark.com
Oct 29 04:12:01.907949 check[95675]: [ 4] thrill.cloudmark.com << 5
Oct 29 04:12:01.907990 check[95675]: [ 6] a=q
Oct 29 04:12:01.908059 check[95675]: [ 5] Connecting to 66.151.150.12 ...
Oct 29 04:12:02.024972 check[95675]: [ 8] Connection established
Oct 29 04:12:02.025090 check[95675]: [ 4] 66.151.150.12 >> 35 server greeting: sn=D&srl=460&a=l&a=cg&ep4=7542-10
Oct 29 04:12:02.025313 check[95675]: [ 4] 66.151.150.12 << 12
Oct 29 04:12:02.025408 check[95675]: [ 6] a=g&pm=csl
Oct 29 04:12:02.084525 check[95675]: [ 4] 66.151.150.12 >> 76
Oct 29 04:12:02.084626 check[95675]: [ 6] response to sent.7
-csl=?
thrill.cloudmark.com
wonder.cloudmark.com
pride.cloudmark.com
.
Oct 29 04:12:02.084831 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with csl=thrill.cloudmark.com
Oct 29 04:12:02.084879 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with csl=wonder.cloudmark.com
Oct 29 04:12:02.084923 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with csl=pride.cloudmark.com
Oct 29 04:12:02.085073 check[95675]: [ 4] 66.151.150.12 << 12
Oct 29 04:12:02.085114 check[95675]: [ 6] a=g&pm=nsl
Oct 29 04:12:02.145958 check[95675]: [ 4] 66.151.150.12 >> 51
Oct 29 04:12:02.146058 check[95675]: [ 6] response to sent.8
-nsl=?
folly.cloudmark.com
joy.cloudmark.com
.
Oct 29 04:12:02.146239 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with nsl=folly.cloudmark.com
Oct 29 04:12:02.146287 check[95675]: [ 8] Discovery Server 66.151.150.12 replying with nsl=joy.cloudmark.com
Oct 29 04:12:02.146408 check[95675]: [ 5] no razorhome, not caching server info to disk
Oct 29 04:12:02.146502 check[95675]: [ 5] no razorhome, not caching server info to disk
Oct 29 04:12:02.146553 check[95675]: [ 8] Using next closest server thrill.cloudmark.com:2703, cached info srl 5047
Oct 29 04:12:02.146618 check[95675]: [ 8] mail 1 has no subject
Oct 29 04:12:02.146768 check[95675]: [ 6] preproc: mail 1.0 went from 40 bytes to 3
Oct 29 04:12:02.146835 check[95675]: [ 6] computing sigs for mail 1.0, len 3
Oct 29 04:12:02.147806 check[95675]: [ 6] Engine (8) didn't produce a signature for mail 1.0
Oct 29 04:12:02.147909 check[95675]: [ 6] skipping whitelist file (empty?): razor-whitelist
Oct 29 04:12:02.147968 check[95675]: [ 6] losing old server connection, 66.151.150.12, for new server, thrill.cloudmark.com
Oct 29 04:12:02.148010 check[95675]: [ 5] disconnecting from server 66.151.150.12
Oct 29 04:12:02.148155 check[95675]: [ 4] 66.151.150.12 << 5
Oct 29 04:12:02.148195 check[95675]: [ 6] a=q
Oct 29 04:12:02.148303 check[95675]: [ 5] Connecting to thrill.cloudmark.com ...
Oct 29 04:12:02.265142 check[95675]: [ 8] Connection established
Oct 29 04:12:02.265314 check[95675]: [ 4] thrill.cloudmark.com >> 36 server greeting: sn=C&srl=5047&a=l&a=cg&ep4=7542-10
Oct 29 04:12:02.265610 check[95675]: [ 4] thrill.cloudmark.com << 25
Oct 29 04:12:02.265654 check[95675]: [ 6] cn=razor-agents&cv=2.61
Oct 29 04:12:02.265779 check[95675]: [ 6] thrill.cloudmark.com is a Catalogue Server srl 5047; computed min_cf=6, Server se: C8
Oct 29 04:12:02.266045 check[95675]: [ 8] Computed supported_engines: 4 8
Oct 29 04:12:02.266167 check[95675]: [ 8] mail 1.0 e4 sig: DXc-2nXPD705qwuy78OtNOq1FcwA
Oct 29 04:12:02.266247 check[95675]: [ 5] mail 1.0 e8 got no sig
Oct 29 04:12:02.266311 check[95675]: [ 8] preparing 1 queries
Oct 29 04:12:02.266419 check[95675]: [ 8] sending 1 batches
Oct 29 04:12:02.266566 check[95675]: [ 4] thrill.cloudmark.com << 52
Oct 29 04:12:02.266611 check[95675]: [ 6] a=c&e=4&ep4=7542-10&s=DXc-2nXPD705qwuy78OtNOq1FcwA
Oct 29 04:12:02.514105 check[95675]: [ 4] thrill.cloudmark.com >> 10
Oct 29 04:12:02.514207 check[95675]: [ 6] response to sent.11
p=0&ct=1
Oct 29 04:12:02.514494 check[95675]: [ 6] mail 1.0 e=4 sig=DXc-2nXPD705qwuy78OtNOq1FcwA: sig not found.
Oct 29 04:12:02.514560 check[95675]: [ 7] method 4: mail 1.0: contention part, skipping
Oct 29 04:12:02.514603 check[95675]: [ 7] method 4: mail 1: all non-contention parts not spam, mail not spam
Oct 29 04:12:02.514646 check[95675]: [ 3] mail 1 is not known spam.
Oct 29 04:12:02.514691 check[95675]: [ 5] disconnecting from server thrill.cloudmark.com
Oct 29 04:12:02.514836 check[95675]: [ 4] thrill.cloudmark.com << 5
Oct 29 04:12:02.514876 check[95675]: [ 6] a=q
debug: Using results from Razor v2.61
debug: Found Razor2 part: part=0 engine=4 ct=1 cf=0
debug: leaving helper-app run mode
debug: Razor2 results: spam? 0 highest cf score: 0
debug: running raw-body-text per-line regexp tests; score so far=0.069
debug: running full-text regexp tests; score so far=0.069
debug: Razor2 is available
debug: DCCifd is not available: no r/w dccifd socket found.
debug: DCC is not available: no executable dccproc found.
debug: Pyzor is not available: pyzor not found
debug: Running tests for priority: 500
debug: RBL: success for 36 of 36 queries
debug: running meta tests; score so far=0.069
debug: running header regexp tests; score so far=1.639
debug: running body-text per-line regexp tests; score so far=1.639
debug: running uri tests; score so far=1.639
debug: running raw-body-text per-line regexp tests; score so far=1.639
debug: running full-text regexp tests; score so far=1.639
debug: Running tests for priority: 1000
debug: running meta tests; score so far=1.639
debug: running header regexp tests; score so far=1.639
debug: running body-text per-line regexp tests; score so far=1.639
debug: running uri tests; score so far=1.639
debug: running raw-body-text per-line regexp tests; score so far=1.639
debug: running full-text regexp tests; score so far=1.639
debug: auto-learn: currently using scoreset 1.
debug: auto-learn: message score: 1.639, computed score for autolearn: 1.639
debug: auto-learn? ham=0.1, spam=12, body-points=0, head-points=0.069, learned-points=0
debug: auto-learn? no: inside auto-learn thresholds, not considered ham or spam
debug: is spam? score=1.639 required=5
debug: tests=FORGED_RCVD_HELO,MISSING_DATE,MISSING_SUBJECT
debug: subtests=
logmsg: clean message (1.6/5.0) for nobody:0 in 1.2 seconds, 194 bytes.
logmsg: result: . 1 - FORGED_RCVD_HELO,MISSING_DATE,MISSING_SUBJECT scantime=1.2,size=194,mid=(unknown),autolearn=no
=== 8< ===
