Bug 6702 - No rule updates since 2011-11-02
Summary: No rule updates since 2011-11-02
Status: RESOLVED FIXED
Alias: None
Product: Spamassassin
Classification: Unclassified
Component: Score Generation (show other bugs)
Version: SVN Trunk (Latest Devel Version)
Hardware: PC All
: P2 blocker
Target Milestone: Undefined
Assignee: SpamAssassin Developer Mailing List
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-11-15 19:14 UTC by Darxus
Modified: 2013-01-20 17:19 UTC (History)
4 users (show)



Attachment Type Modified Status Actions Submitter/CLA Status

Note You need to log in before you can comment on or make changes to this bug.
Description Darxus 2011-11-15 19:14:56 UTC
$ host -t txt 1.3.3.updates.spamassassin.org
1.3.3.updates.spamassassin.org descriptive text "1195874"

This matches the updates_spamassassin_org.cf I downloaded on 2011-11-02:
# UPDATE version 1195874

2011-11-02 is the same day Kevin changed the DNS record for the version in trunk to a CNAME to v3.3.2, which *might* have broken score generation - bug 6644.

ruleqa was also not running recently (bug 6701), but it's back up, and we still have no rule update, so I don't *think* it's related.
Comment 1 John Hardin 2011-11-16 05:56:44 UTC
72_scores.cf was updated on 11/15, so an update _should_ have gone out...

http://svn.apache.org/viewvc/spamassassin/trunk/rulesrc/scores/72_scores.cf?view=log
Comment 2 Darxus 2011-11-16 16:08:26 UTC
Weird.  It still hasn't:

$ host -t txt 1.3.3.updates.spamassassin.org
1.3.3.updates.spamassassin.org descriptive text "1195874"
Comment 3 Darxus 2011-11-21 18:49:27 UTC
Want to revert the DNS change from bug 6658 to see if that helps?
Comment 4 Kevin A. McGrail 2011-11-21 19:45:58 UTC
(In reply to comment #3)
> Want to revert the DNS change from bug 6658 to see if that helps?

I'd like some idea that this is the cause before doing so.  We've had a lot of changes.
Comment 5 Darxus 2011-11-21 21:52:46 UTC
What command or commands are automatically run to generate this stuff?

Is build/mkupdates/update-rules-3.3 involved?

I noticed it creates a directory in https://svn.apache.org/repos/asf/spamassassin/tags/ named sa-update_3.4.0_ and that the latest one of those is https://svn.apache.org/repos/asf/spamassassin/tags/sa-update_3.4.0_20111121085100/
which is today's date.

This same script looks like it's supposed to write the DNS update.  Where is the output of this going?  Is it triggering one of these?

179   mv $dnsfile.new $dnsfile || exit $?
181   echo "failed to create $dnsfile.new" 1>&2 ; exit 1

Any chance the problem could be write permissions on the DNS zone file?  I see Kevin said (bug 6644 comment 20) he did a "chmod 1777" on the directory containing it?  Maybe it needed to be a recursive chmod and wasn't?  Looks like the full path is:
/var/named/updates.spamassassin.org.d/3.4.0

What is the modification date on that file?  Is it getting updated?  Or has it been unmodified since 2011-11-02, when Kevin made a DNS change?
Comment 6 Darxus 2011-11-21 22:06:01 UTC
Use of build/mkupdates/update-rules-3.3 is mentioned briefly in build/README.
Comment 7 Kevin A. McGrail 2011-11-21 22:31:15 UTC
(In reply to comment #5)
> What command or commands are automatically run to generate this stuff?

OK, so in /var/www/buildbot.spamassassin.org/updatestage is something interesting!

So we have our Aug 28th update:
-r-xr--r--   1 updatesd dns       236977 Aug 27 03:32 1162027.tar.gz
-r-xr--r--   1 updatesd dns          823 Aug 27 03:32 1162027.tar.gz.asc
-r-xr--r--   1 updatesd dns           80 Aug 27 03:32 1162027.tar.gz.sha1

Then a gap until Oct when we started working on time:
-r-xr--r--   1 updatesd dns       238003 Oct 30 03:45 1190771.tar.gz
-r-xr--r--   1 updatesd dns          823 Oct 30 03:45 1190771.tar.gz.asc
-r-xr--r--   1 updatesd dns           79 Oct 30 03:45 1190771.tar.gz.sha1
-r-xr--r--   1 updatesd dns       238016 Oct 31 03:54 1195131.tar.gz
-r-xr--r--   1 updatesd dns          823 Oct 31 03:54 1195131.tar.gz.asc
-r-xr--r--   1 updatesd dns           80 Oct 31 03:54 1195131.tar.gz.sha1
-r-xr--r--   1 updatesd dns       237997 Nov  1 07:20 1195374.tar.gz
-r-xr--r--   1 updatesd dns          823 Nov  1 07:20 1195374.tar.gz.asc
-r-xr--r--   1 updatesd dns           80 Nov  1 07:20 1195374.tar.gz.sha1

Then an update after I worked on DNS:

-r-xr--r--   1 updatesd dns       238078 Nov  2 03:10 1195874.tar.gz
-r-xr--r--   1 updatesd dns          823 Nov  2 03:10 1195874.tar.gz.asc
-r-xr--r--   1 updatesd dns           80 Nov  2 03:10 1195874.tar.gz.sha1


Then a gap until Nov 17th but I think
-rw-r--r--   1 updatesd dns       179435 Nov 17 08:50 1203111.tar.gz
-rw-r--r--   1 updatesd dns          823 Nov 17 08:50 1203111.tar.gz.asc
-rw-r--r--   1 updatesd dns           84 Nov 17 08:50 1203111.tar.gz.sha1
-rw-r--r--   1 updatesd dns       180434 Nov 18 08:50 1203534.tar.gz
-rw-r--r--   1 updatesd dns          823 Nov 18 08:51 1203534.tar.gz.asc
-rw-r--r--   1 updatesd dns           84 Nov 18 08:51 1203534.tar.gz.sha1
-rw-r--r--   1 updatesd dns       180436 Nov 19 08:50 1203963.tar.gz
-rw-r--r--   1 updatesd dns          823 Nov 19 08:51 1203963.tar.gz.asc
-rw-r--r--   1 updatesd dns           84 Nov 19 08:51 1203963.tar.gz.sha1
-rw-r--r--   1 updatesd dns       180508 Nov 20 08:50 1204136.tar.gz
-rw-r--r--   1 updatesd dns          823 Nov 20 08:51 1204136.tar.gz.asc
-rw-r--r--   1 updatesd dns           84 Nov 20 08:51 1204136.tar.gz.sha1
-rw-r--r--   1 updatesd dns       180507 Nov 21 08:50 1204403.tar.gz
-rw-r--r--   1 updatesd dns          823 Nov 21 08:51 1204403.tar.gz.asc
-rw-r--r--   1 updatesd dns           84 Nov 21 08:51 1204403.tar.gz.sha1

OK, so then let's look at the files involved in that chmod:

total 24
drwxrwxrwt   2 updatesd dns          512 Nov 21 08:51 .
drwxr-xr-x   9 root     root         512 Nov  2 04:13 ..
-rw-r--r--   1 updatesd other         37 Mar 12  2009 3.1.0
-rw-r--r--   1 updatesd other         19 Jan  1  2010 3.2.0
-rw-r--r--   1 updatesd dns           20 Nov  2 03:07 3.3.0
-rw-r--r--   1 updatesd dns           19 Feb 23  2010 3.3.0-20100216
-rw-r--r--   1 updatesd dns           22 Jan 20  2011 3.3.0-20110127
-rw-r--r--   1 updatesd dns           20 Nov  2 03:08 3.3.1
-rw-r--r--   1 updatesd dns           19 Feb 23  2010 3.3.1-20100218
-rw-r--r--   1 updatesd dns            0 Feb 18  2010 3.3.10
-rw-r--r--   1 updatesd dns           20 Nov  2 03:09 3.3.2
-rw-r--r--   1 updatesd dns           20 Nov  2 03:10 3.3.3
-rw-r--r--   1 updatesd dns            0 Feb 18  2010 3.3.4
-rw-r--r--   1 updatesd dns            0 Feb 18  2010 3.3.5
-rw-r--r--   1 updatesd dns            0 Feb 18  2010 3.3.6
-rw-r--r--   1 updatesd dns            0 Feb 18  2010 3.3.7
-rw-r--r--   1 updatesd dns            0 Feb 18  2010 3.3.8
-rw-r--r--   1 updatesd dns            0 Feb 18  2010 3.3.9
-rw-r--r--   1 updatesd dns           22 Nov 21 08:51 3.4.0
bash-3.00# cat 3.4.0 

0.4.3   TXT     "1204403"

This shows that run_part2 is working.

So why is 3.3.2 and 3.3.3 last updated Nov 2?

My guess is /home/updatesd/svn/mkupdates-with-scores/mkupdate-with-scores run from cron as user updatesd

So I'm running it manually to see what happens/doesn't happen.
Comment 8 Kevin A. McGrail 2011-11-22 00:39:02 UTC
Apparently run_part2 is for trunk updates based on:

/home/updatesd/svn/mkupdates-with-scores/mkupdate-with-scores

"This script is similar to the run_part2 script used for trunk rule updates."

So apparently we mean to generate trunk rules that don't have score...

Anyway, still no idea on the error.  These scripts are not quick and loaded with output.  I need to try and break out their loop structure and see if I can find an error.

A permission issue or svn issue I caused would make a lot of sense.
Comment 9 Kevin A. McGrail 2011-11-22 19:18:15 UTC
(In reply to comment #8)
> Apparently run_part2 is for trunk updates based on:
> 
> /home/updatesd/svn/mkupdates-with-scores/mkupdate-with-scores
> 
> "This script is similar to the run_part2 script used for trunk rule updates."
> 
> So apparently we mean to generate trunk rules that don't have score...
> 
> Anyway, still no idea on the error.  These scripts are not quick and loaded
> with output.  I need to try and break out their loop structure and see if I can
> find an error.
> 
> A permission issue or svn issue I caused would make a lot of sense.


Plan at the moment is to:

1 - look at updatesd cron spool and try and add some logging

2 - su to updatesd, log the terminal and run the commands and review output.  Hopefully something jumps out like an error...
Comment 10 mykel 2011-12-07 02:02:55 UTC
Still finding my feet looking through this, but it looks to me that the mkupdate-with-scores may be failing due to the addition of the T_HEADER_FROM_DIFFERENT_DOMAINS rule which requires check_euqal_from_domains() in HeaderEval.pm which is not in 3.3.1/3.3.2 (see bug 6487).  If I am reading rulesqa right, the rule was added in 1196505 on Nov 2.

In which case the DNS change is a red herring and purely a coincidence of timing.
Comment 11 Darxus 2011-12-08 17:45:33 UTC
Nice.  Kevin, can you pull HEADER_FROM_DIFFERENT_DOMAINS out of your sandbox?  
( rulesrc/sandbox/kmcgrail/20_freemail.cf )

mykel, could you add some documentation somewhere?  Maybe in the vicinity of http://wiki.apache.org/spamassassin/InfraNotes ?
Comment 12 Kevin A. McGrail 2011-12-08 18:06:40 UTC
I saw his note and it's a good idea but wouldn't this make any rules that rely on code changes fail updates?  I'm skeptical but willing to try about anything.

svn commit -m 'Disabling check_equal_from_domains() rule to see if it helps updates bug 6702'
Sending        kmcgrail/20_freemail.cf
Transmitting file data .
Committed revision 1212010.

regards,
KAM
Comment 13 mykel 2011-12-09 03:36:58 UTC
Thanks KAM.  Once the mass checks are done on that version hopefully the update will go through (my local testing suggests it should be fine).

It would make rules that depend on code changes fail updates, but I believe that can be handled by version based conditions  i.e. "if version >= 3.004000"

Darxus - happy to write something up, but I'm just inferring what's going on inside the SA infrastructure from looking at a local copy of the script from svn.  Not that I have permission to update that page..
Comment 14 Darxus 2011-12-09 04:04:31 UTC
(In reply to comment #13)
> Darxus - happy to write something up, but I'm just inferring what's going on
> inside the SA infrastructure from looking at a local copy of the script from
> svn.  Not that I have permission to update that page..

Just create an account on the wiki if you haven't, then post to dev@ with your username requesting write access.  
( http://wiki.apache.org/spamassassin/#Editing_This_Wiki - I didn't see it either.)
Comment 15 mykel 2011-12-10 04:16:07 UTC
$ host -t txt 1.3.3.updates.spamassassin.org
1.3.3.updates.spamassassin.org descriptive text "1212281"

and my sa-update on a 'normal' server now updated as expected.  Looks to be fixed.
Comment 16 Kevin A. McGrail 2011-12-10 14:19:44 UTC
(In reply to comment #15)
> $ host -t txt 1.3.3.updates.spamassassin.org
> 1.3.3.updates.spamassassin.org descriptive text "1212281"
> 
> and my sa-update on a 'normal' server now updated as expected.  Looks to be
> fixed.

I concur.  

-rw-r--r--   1 updatesd dns           20 Dec 10 03:05 3.3.0
-rw-r--r--   1 updatesd dns           20 Dec 10 03:06 3.3.1
-rw-r--r--   1 updatesd dns           20 Dec 10 03:07 3.3.2
-rw-r--r--   1 updatesd dns           20 Dec 10 03:08 3.3.3

Question for you, what was the error string you saw in mkupdate-with-scores?  I need to find out where it is being logged.  

From looking today, it might be in email only and the only people who got that email were Justin, Daryl and Theo.  I've just added myself to the list.

Many thanks Mykel!  You were right.  DNS was a red-herring.
Comment 17 Darxus 2011-12-10 18:31:58 UTC
(In reply to comment #15)
> $ host -t txt 1.3.3.updates.spamassassin.org
> 1.3.3.updates.spamassassin.org descriptive text "1212281"
> 
> and my sa-update on a 'normal' server now updated as expected.  Looks to be
> fixed.

Nice.  I'd like to leave this open till it gets documented somewhere.  

Mykel, to be clear, we seem to really be lacking in understanding of how this works, and how to figure out what broke.  You know stuff about this that nobody else (currently participating) does, so anything you can write down would be great.

I changed my script that posts "Rule updates are too old" to the dev list to run daily.
Comment 18 mykel 2011-12-10 23:41:28 UTC
KAM,

The mkupdates-with-scores runs sa-update for each version in the 3.3 series.  Originally I noticed the sa-update's were returning with exit code 4 (rather than 0 which would have made the script go on and do the DNS update).  The actual error nestled in the mass of output was:

rules: failed to run T_HEADER_FROM_DIFFERENT_DOMAINS test, skipping:
        (Can't locate object method "check_equal_from_domains" via package "Mail
::SpamAssassin::PerMsgStatus" at (eval 1054) line 1531.
)

Maybe it would be sensible to run the sa-update without the -D so that the errors are a little easier to find.  There are still a bunch of warnings about deprecated behaviour and other non-fatal errors, but it reduces the output to dig through to a manageable amount.

I was just looking at the logging from my local copy of mkupdates-with-scores which just comes out stderr - I don't know where this logging data goes in your real infrastructure.

Darxus,

I will get to it, but my skill lies not in working out things work, but why they don't, so it'll take me a little while to dig into it more to get a better picture.  I'm just extracting knowledge from the script itself - there are specifics of the implementation that I have to infer.  But give me a little time and I'll bash something out.
Comment 19 Kevin A. McGrail 2011-12-11 15:45:20 UTC
Thanks Mykel,

The exit status and the error code will be brilliant in fixing this issue.  As soon as I figure out where the logging goes...

Here's what I know:

The script /mkupdate-with-scores is run by the updatesd user via cron on spamassassin.zones.apache.org.

It is called from do-stable-update-with-scores.

25 2 * * * bash /export/home/updatesd/svn/mkupdates-with-scores/do-stable-update-with-scores

It runs at 2:25AM UTC.

Based on Mykel's notes below, we are looking for this error:

rules: failed to run T_HEADER_FROM_DIFFERENT_DOMAINS test, skipping:
        (Can't locate object method "check_equal_from_domains" via package
"Mail
::SpamAssassin::PerMsgStatus" at (eval 1054) line 1531.
)

As of yet, I'm not finding the logs.  I think they would be emailed to updatesd which I am now on the list to receive.

I think changing the script do-stable-update-with-scores to check for a non-zero exit is a good idea.

I don't think getting rid of sa-update -D is a good idea but I do know what Mykel's talking about.  It's a lot of output.  If I could find the live copy, I can find these errors.
Comment 20 Kevin A. McGrail 2011-12-12 15:30:01 UTC
(In reply to comment #19)
> Thanks Mykel,
> 
> The exit status and the error code will be brilliant in fixing this issue.  As
> soon as I figure out where the logging goes...

Logging is via cron and I am now receiving it.  I have a feeling the files from cron might exceed some sizes in some sendmail.mc's.

 
> I think changing the script do-stable-update-with-scores to check for a
> non-zero exit is a good idea.
> 
> I don't think getting rid of sa-update -D is a good idea but I do know what
> Mykel's talking about.  It's a lot of output.  If I could find the live copy, I
> can find these errors.

Closing pending the next problem we have where hopefully we can look at these issues!
Comment 21 Darxus 2011-12-12 20:21:16 UTC
(In reply to comment #19)
> I think changing the script do-stable-update-with-scores to check for a
> non-zero exit is a good idea.

Has that been done?  Should this be left open until it is?  It would also be nice if we got an email to dev@ whenever it decides not to generate scores due to insufficient corpora.
Comment 22 Kevin A. McGrail 2011-12-12 21:50:05 UTC
(In reply to comment #21)
> (In reply to comment #19)
> > I think changing the script do-stable-update-with-scores to check for a
> > non-zero exit is a good idea.
> 
> Has that been done?  Should this be left open until it is?  It would also be
> nice if we got an email to dev@ whenever it decides not to generate scores due
> to insufficient corpora.

I would leave it closed until the next issue.  

However, I did add exit status checks which led to more infrastructure issues.  It seems the script do-stable-update-with-scores isn't in SVN even though it's in an SVN dir.  

I'm adding and committing them now.

So hopefully, my changes to add exit status doesn't break anything. I had stupidly expected to run svn diff on the long-standing script to confirm my changes.  

svn should show the file now in /export/home/updatesd/svn/mkupdates-with-scores/do-stable-update-with-scores

Fingers crossed for tonight's run...
Comment 23 John Hardin 2011-12-12 23:08:15 UTC
(In reply to comment #21)
> It would also be
> nice if we got an email to dev@ whenever it decides not to generate scores due
> to insufficient corpora.

+1

Actually, a mail for both outcomes would be nice.
Comment 24 Kevin A. McGrail 2011-12-13 15:54:01 UTC
> Fingers crossed for tonight's run...

Good news: I received the output and the errors were clearer

Bad news: I missed an s

Running mkupdate-with-score...

/export/home/updatesd/svn/mkupdates-with-scores/do-stable-update-with-scores: line 20: /home/updatesd/svn/mkupdates-with-scores/mkupdate-with-score: No such file or directory
Exit Status 127 is not zero for mkupdate-with-score

svn commit -m 'Added an s to the script name'              
Sending        do-stable-update-with-scores
Transmitting file data .
Committed revision 1213749.

Attempting to run just mkupdate-with-scores from a temporary script (so that the correct perl is used, etc.) and see if we can publish things now.
Comment 25 Kevin A. McGrail 2013-01-20 17:19:21 UTC
This was resolved and not updated.