I think we still have a race condition where a mirror can grab a file and we need to create the temp file in a non sync'd location.  So 7566 is still not 100% resolved.

Dave, would this fall under the time period for the race condition?  I'm guessing no and that this is just a transient issue.  I downloaded manually and bitwell.fi seems fine.

I think this could still be the result of caching.

I have been thinking about the best way to handle our problem with the same SVN version having two different rulesets built (tick from rule promotions and tock from the masscheck score updates).

For now I think we can disable the ruleset build from the rule promotions since the masscheck has been running well for a while.  Then I can figure out some logic to best detect when the masscheck doesn't update the ruleset so the rule promotions can build a new ruleset.

Bottom line is we only want one ruleset to be built per SVN tagged revision so there has to be some coordination between the tick and tock.  Maybe I can do something as simple as check the last ruleset build easily with the find command for being more than ~20 hours old in the rule promotion script.

+1 to anything that gets rid of two PUBLISHED files with the same name.

Trying to resolve this with commit rev 1828938.  I will continue to monitor this situation until I can make this recent ruleset from the mkupdates (masscheck) detection work.

Maybe not related, but as the log shows the same mirror, I thought I would mention the error from last night:

Apr 13 06:54:33.019 [6757] dbg: http: url: http://sa-update.bitwell.fi/1828957.tar.gz
(snip)
Apr 13 06:54:33.312 [6757] dbg: sha1: verification wanted: 1288800d8145856619ea7aae6ca5439c168c80cc
Apr 13 06:54:33.312 [6757] dbg: sha1: verification result: 1288800d8145856619ea7aae6ca5439c168c80cc
Apr 13 06:54:33.312 [6757] dbg: channel: populating temp content file /tmp/.spamassassin67575yBTDDtmp
Apr 13 06:54:33.319 [6757] dbg: gpg: populating temp signature file
Apr 13 06:54:33.319 [6757] dbg: gpg: calling gpg
Apr 13 06:54:33.342 [6757] dbg: gpg: gpg: Signature made Thu 12 Apr 2018 10:31:17 AM CEST using RSA key ID 24F434CE
Apr 13 06:54:33.342 [6757] dbg: gpg: [GNUPG:] BADSIG 6C55397824F434CE updates.spamassassin.org Signing Key <release@spamassassin.org>
Apr 13 06:54:33.342 [6757] dbg: gpg: gpg: BAD signature from "updates.spamassassin.org Signing Key <release@spamassassin.org>"
gpg: process '/usr/bin/gpg' finished: exit 1
error: GPG validation failed!
The update downloaded successfully, but the GPG signature verification
failed.
channel: GPG validation failed, channel failed
Apr 13 06:54:33.343 [6757] dbg: generic: cleaning up temporary directory/files
Apr 13 06:54:33.343 [6757] dbg: generic: cleaning directory /tmp/.spamassassin67579SldXotmp
Apr 13 06:54:33.343 [6757] dbg: diag: updates complete, exiting with code 4

Interesting.  A bad RSA sig?

How could I check this?

I think this is the same issue with two sets of rulesets being generated with the same name.  I have put something on the server to try to prevent this but I don't have any logging on my SA mirror to show me when updates are happening.  I will enable logging of the rsync today on my mirrors.

Fingers crossed...

URL: http://svn.apache.org/viewvc?rev=1829141&view=rev
Log:
Had logic backwards for recent ruleset test from masscheck processing.

Modified:
    spamassassin/trunk/build/mkupdates/run_nightly

Modified: spamassassin/trunk/build/mkupdates/run_nightly
URL: http://svn.apache.org/viewvc/spamassassin/trunk/build/mkupdates/run_nightly?rev=1829141&r1=1829140&r2=1829141&view=diff
==============================================================================
--- spamassassin/trunk/build/mkupdates/run_nightly (original)
+++ spamassassin/trunk/build/mkupdates/run_nightly Sat Apr 14 14:07:01 2018
@@ -171,7 +171,7 @@ make_tarball_for_version() {
   # Integrate with masscheck ruleset updates to prevent duplicates
   RECENT=`find $HOME/tmp/mkupdate-with-scores -name \*.tar.gz -mmin -480`
 
-  if [[ ! -z "$RECENT" ]]; then
+  if [[ -z "$RECENT" ]]; then
 
     echo "Recent ruleset from mkupdate-with-scores (massheck) NOT found."
     echo "Proceeding with a ruleset publish..."

BTW, Jarif said he IS using caching so the issues are related.  I asked for clarification on list.

Last night's log on one server. The "verification wanted" looks not quite as it should be:

Apr 19 06:43:08.179 [17781] dbg: sha1: verification wanted: 3.4
Apr 19 06:43:08.179 [17781] dbg: sha1: verification result: fa0de9421fff05f4717860a0aa3f00c1545650db
channel: SHA1 verification failed, channel failed

My last change to flip the logic seems to have worked and was confirmed by a mirror admin.

Is there a way to get this fix for my Debian Jessie and Stretch boxes without compiling? Or a workaround?

This was a mirror-side problem that was caused by two rulesets with the same name being generated hours appart and the caching on the mirror server was causing problems.  I have fixed the rulset generation so only one gets generated now.

Is this still a problem in your logs?

Yes, I still received mails from some servers the last days. Haven't checked all of them, but e.g. the first one I checked has this in the logs:

May  2 07:05:13.285 [26808] dbg: channel: selected mirror http://sa-update.bitwell.fi
May  2 07:05:13.286 [26808] dbg: http: url: http://sa-update.bitwell.fi/1830658.tar.gz
...
May  2 07:05:13.432 [26808] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1830658.tar.gz.asc -- http://sa-update.bitwell.fi/1830658.tar.gz.asc
May  2 07:05:13.491 [26808] dbg: http: process [26813], exit status: 0
May  2 07:05:13.492 [26808] dbg: sha1: verification wanted: 3.4
May  2 07:05:13.492 [26808] dbg: sha1: verification result: fa0de9421fff05f4717860a0aa3f00c1545650db
channel: SHA1 verification failed, channel failed

I am pretty confident that the last error reported above is a different issue.  We do seem to have a problem with one of the two mirrors behind sa-update.bitwell.fi being DOWN.  Our hourly report to the sysadmins list is showing that.

The original problem was caused by caching issues when two rulesets were being created with the same filename.  We shouldn't have been creating two slightly different rulesets with the same name and I have fixed that a few weeks ago.

The original post on 4/11 seems to be a different error code/message.

Could you please advise what I should do next? Open another ticket for this next problem?

Larsen, are you still seeing issues with the bitwell.fi server mirror out of rotation?

Yes, last night I got error mails from three of my servers.

Can you send the errors, please?  I'm guessing you might have a cached MIRRORED.BY file.  I seem to recall there is a way to force a mirror check.

It's what I posted before ("verification wanted: 3.4").

Anything else I can add?

What server is it trying?  If it's bitwell.fi, that's a known issue.

Run sa-update with  --refreshmirrors        Force the MIRRORED.BY file to be updated

Heading out for the weekend, will continue on Monday.

Afaiu, I have to refresh the mirror list on all servers to resolve the problem with bitwell.fi. Is that correct?

Yes and No.  You should be randomly getting a mirror so the chances should be low.  But refreshing it will definitely resolve the issue because bitwell is off the mirror list.

We have several servers so there is probably always one that gets bitwell.fi hence I regularly got mails (from varying servers).

Agreed.  You'll need to run the refreshmirrors on all your servers.

The result of "sa-update -v --refreshmirrors":
- 9 servers had been updated automatically before it seems
- 8 servers got updated
- 7 servers did not get updated

The servers that didn't get updated, were supposed to have the newest version (according to updates_spamassassin_org.cf, afaict) but did have an md5sum of the old version.

# grep version /var/lib/spamassassin/3.004001/updates_spamassassin_org.cf
# UPDATE version 1831022

# grep bitwell /var/lib/spamassassin/3.004001/updates_spamassassin_org/MIRRORED.BY
http://sa-update.bitwell.fi/ weight=10

# md5sum /var/lib/spamassassin/3.004001/updates_spamassassin_org/MIRRORED.BY
4b64cf74033c75559a877a4ab22d0552  /var/lib/spamassassin/3.004001/updates_spamassassin_org/MIRRORED.BY

# sa-update --refreshmirrors -D
...
May  7 09:45:49.612 [25348] dbg: channel: channel pre file /var/lib/spamassassin/3.004001/updates_spamassassin_org.pre
May  7 09:45:49.612 [25348] dbg: channel: metadata version = 1831022, from file /var/lib/spamassassin/3.004001/updates_spamassassin_org.cf
May  7 09:45:49.620 [25348] dbg: dns: 1.4.3.updates.spamassassin.org => 1831022, parsed as 1831022
May  7 09:45:49.620 [25348] dbg: channel: current version is 1831022, new version is 1831022, skipping channel


I took one server and manually set the version number to 1831021, ran refreshmirrors, mirrors received an update, and afterwards the new md5sum was correct with bitwell being commented out.


There is no need for me to do this, as I can easily correct the remaining servers, but perhaps you would like to further investigate why some servers had the new version number but still the old mirror list? If not that's fine for me.

Larsen, if you run the refresh mirrors and get bitwell.fi STILL in the mirrors list, that is a problem.

Is that the case?

Not exactly. Some servers have a "updates_spamassassin_org.cf" containing "version 1831022", where the bitwell entry should be COMMENTED, but it still is ACTIVE.

That updates_spamassassin_org.cf implies that I think you are using a custom rules update channel.

I don't believe a stock installation and use of sa-update will create that file.  I'm not sure if what you are seeing is expected behavior or not, i.e. should sa-update --refreshmirrors update a file like updates_spamassassin_org.cf as well or do you have to maintain that yourself.

Then maybe it's because of Plesk. I will simply fix that manually.

I would guess that plesk is controlling that, yes.  Interesting info, thanks

Has bitwell.fi been put into the mirror list again?

I started to receive the same problems again some days ago, and Plesk tells me they are using the "vendor-provided package".