You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@spamassassin.apache.org by Matus UHLAR - fantomas <uh...@fantomas.sk> on 2018/09/05 08:08:24 UTC
repeated sa-update problems
Hello,
I (imho too often) get problems when running sa-update (Debian 8, SA 3.4.0)
/etc/cron.daily/spamassassin:
sa-update failed for unknown reasons
in debug mode I found out:
Sep 5 07:38:31.810 [16137] dbg: channel: selected mirror http://sa-update.secnap.net
Sep 5 07:38:31.810 [16137] dbg: http: url: http://sa-update.secnap.net/1840016.tar.gz
Sep 5 07:38:31.810 [16137] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1840016.tar.gz, update
Sep 5 07:38:31.810 [16137] dbg: util: executable for curl was found at /usr/bin/curl
Sep 5 07:38:31.810 [16137] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1840016.tar.gz -z 1840016.tar.gz -- http://sa-update.secnap.net/1840016.tar.gz
Sep 5 07:38:33.211 [16137] dbg: http: process [16166], exit status: 0
...
Sep 5 07:38:33.799 [16137] dbg: sha1: verification wanted: ea88487c6e9cd48fb3e546606eac2effe4a3a91c
Sep 5 07:38:33.799 [16137] dbg: sha1: verification result: 953efe8f531a5a87f6d2d5a65b78b05e55599abc
channel: SHA1 verification failed, channel failed
the resulting file:
# ls -lctr --full-time 1840016.tar.gz
-rw-r--r-- 1 debian-spamd debian-spamd 1 2018-09-05 07:38:33.205411724 +0200 1840016.tar.gz
running the curl manually downloads correct file:
# ls -lct --full-time /tmp/1840016.tar.gz
-rw-r--r-- 1 root root 283416 2018-09-05 09:10:02.572034800 +0200 /tmp/1840016.tar.gz
with correct checksum:
# sha1sum 1840016.tar.gz /tmp/1840016.tar.gz
953efe8f531a5a87f6d2d5a65b78b05e55599abc 1840016.tar.gz
ea88487c6e9cd48fb3e546606eac2effe4a3a91c /tmp/1840016.tar.gz
we are behind fortigate firewall, which shows this relevant line:
Sep 5 07:38:34 fgt date=2018-09-05,time=07:38:34,devname=FGT,devid=XXX,logid=0000000013,type=traffic,subtype=forward,level=notice,vd=root,srcip=x.x.x.x,srcport=60665,srcintf="internal",dstip=204.89.241.6,dstport=80,dstintf="wan1",poluuid=9a0df156-900e-51e8-d4d5-7b4de8e07615,sessionid=48968219,proto=6,action=close,policyid=62,policytype=policy,dstcountry="United States",srccountry="Reserved",trandisp=snat,transip=y.y.y.y,transport=60665,service="HTTP",duration=1,sentbyte=423,rcvdbyte=604,sentpkt=6,rcvdpkt=4,appcat="unscanned",wanin=388,wanout=103,lanin=103,lanout=388
Sep 5 09:10:03 fgt date=2018-09-05,time=09:10:03,devname=FGT,devid=XXX,logid=0000000013,type=traffic,subtype=forward,level=notice,vd=root,srcip=x.x.x.x,srcport=36269,srcintf="internal",dstip=204.89.241.6,dstport=80,dstintf="wan1",poluuid=9a0df156-900e-51e8-d4d5-7b4de8e07615,sessionid=49153868,proto=6,action=close,policyid=62,policytype=policy,dstcountry="United States",srccountry="Reserved",trandisp=snat,transip=y.y.y.y,transport=36269,service="HTTP",duration=2,sentbyte=6554,rcvdbyte=294053,sentpkt=124,rcvdpkt=199,appcat="unscanned",wanin=283697,wanout=98,lanin=98,lanout=283697
This kind of error happens with different mirrors.
Now my questions:
- is this possible problem with mirrors?
- when do mirrors update?
- do mirrors updates propagate atomically?
or should I dig into that deeper to find out what happens?
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
Fucking windows! Bring Bill Gates! (Southpark the movie)
Fwd: repeated sa-update problems
Posted by "Kevin A. McGrail" <km...@apache.org>.
FYI
-------- Forwarded Message --------
Subject: Re: repeated sa-update problems
Date: Mon, 8 Oct 2018 16:43:42 +0200
From: Matus UHLAR - fantomas <uh...@fantomas.sk>
To: users@spamassassin.apache.org
>On 20.09.18 16:05, Matus UHLAR - fantomas wrote:
>>I looked at update times and they are different each day - debian script
>>sleeps random number of seconds (up to one hour) in order to lower the
>>impact at mirror servers.
>>
>>I have removed the "--fail" option from curl and will look at error message
>>if there's any.
>>
>>I'll keep you updated and will fill bugreport if I'm able to find out
>>anything useful.
I was able to repeat this problem now:
# /usr/bin/curl --verbose -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -- http://sa-update.spamassassin.org/1843052.tar.gz
* Hostname was NOT found in DNS cache
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Trying 64.142.56.146...
* Connected to sa-update.spamassassin.org (64.142.56.146) port 80 (#0)
> GET /1843052.tar.gz HTTP/1.1
> User-Agent: curl/7.38.0
> Host: sa-update.spamassassin.org
> Accept: */*
>
0 0 0 0 0 0 0 0 --:--:-- 0:00:11 --:--:-- 0< HTTP/1.1 200 OK
< Date: Mon, 08 Oct 2018 14:16:19 GMT
* Server Apache/2.4.6 (CentOS) is not blacklisted
< Server: Apache/2.4.6 (CentOS)
< Last-Modified: Mon, 08 Oct 2018 03:19:20 GMT
< ETag: "4600c-577af16429e00"
< Accept-Ranges: bytes
< Content-Length: 286732
< Content-Type: application/x-gzip
<
{ [data not shown]
0 280k 0 1 0 0 0 0 --:--:-- 0:00:13 --:--:-- 0* transfer closed with 286731 bytes remaining to read
* Closing connection 0
curl: (18) transfer closed with 286731 bytes remaining to read
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 1 Oct 8 16:16 1843052.tar.gz
look at today's debug log says:
Oct 8 07:12:59.899 [20257] dbg: channel: selected mirror http://sa-update.spamassassin.org
Oct 8 07:12:59.899 [20257] dbg: http: url: http://sa-update.spamassassin.org/1843052.tar.gz
Oct 8 07:12:59.899 [20257] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1843052.tar.gz, new
Oct 8 07:12:59.899 [20257] dbg: util: executable for curl was found at /usr/bin/curl
Oct 8 07:12:59.899 [20257] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -- http://sa-update.spamassassin.org/1843052.tar.gz
Oct 8 07:13:15.385 [20257] dbg: http: process [20258], exit status: 4608
Oct 8 07:13:15.385 [20257] dbg: channel: selected mirror http://sa-update.ena.com
Oct 8 07:13:15.385 [20257] dbg: http: url: http://sa-update.ena.com/1843052.tar.gz
Oct 8 07:13:15.385 [20257] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1843052.tar.gz, update
Oct 8 07:13:15.385 [20257] dbg: util: executable for curl was found at /usr/bin/curl
Oct 8 07:13:15.385 [20257] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
Oct 8 07:13:15.889 [20257] dbg: http: process [20272], exit status: 0
This looks that invalid file was downloaded from sa-update.spamassassin.org,
and while next curl invocation succeeded with exit code 0, the file was not
overridden:
# /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 243 Oct 8 16:21 1843052.tar.gz
# /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 243 Oct 8 16:21 1843052.tar.gz
# rm 1843052.tar.gz
# /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 286732 Oct 8 05:19 1843052.tar.gz
(the file size changed to 243 because of my tests).
further look at logs says that all failed downloads were from
sa-update.spamassassin.org:
Sep 28 07:43:07.888 [7018] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842077.tar.gz -- http://sa-update.spamassassin.org/1842077.tar.gz
Sep 28 07:43:21.973 [7018] dbg: http: process [7019], exit status: 4608
Oct 5 06:35:10.552 [29702] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842787.tar.gz -- http://sa-update.spamassassin.org/1842787.tar.gz
Oct 5 06:35:29.199 [29702] dbg: http: process [29705], exit status: 4608
Oct 7 07:17:37.644 [30424] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843008.tar.gz -- http://sa-update.spamassassin.org/1843008.tar.gz
Oct 7 07:18:11.394 [30424] dbg: http: process [30427], exit status: 4608
btw, when repeating attempts to download from sa-update.spamassassin.org,
many of them failed.
It looks to me that:
1. sa-update.spamassassin.org has some rate limiting or problem with tcp/ip
(accelerator?)
2. the script does NOT remove downloaded file when download fails and curl
is NOT instructed to do so.
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
One OS to rule them all, One OS to find them,
One OS to bring them all and into darkness bind them
Re: repeated sa-update problems
Posted by Matus UHLAR - fantomas <uh...@fantomas.sk>.
Hello,
revoking old thread.
I think I have found some of problems:
1.
looking at old debug outputs, seems that everytime we've had problem,
sa-update first tried to fetch from http://sa-update.spamassassin.org
further fetching from other mirrors did not help, due to issues below.
I feel that I incorrectly blamed the other mirrors for this, sorry.
I don't have output from Sep 05 and Sep 20 stored anymore, but I can guess
it was the same problem.
I asked out fortinet team to look at that issue.
I am currently unable to fetch the update from sa-update.spamassassin.org
- are there any download limits implemented on that server?
2.
when those problems happened, curl returned "18", in 3.4.0 shown as 4608
(18*256) which means:
18 Partial file. Only a part of the file was transferred.
- just as it did today:
Dec 17 07:06:59.051 [11809] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1849014.tar.gz -- http://sa-update.spamassassin.org/1849014.tar.gz
Dec 17 07:07:17.618 [11809] dbg: http: process [11812], exit status: exit 18
so, only partial content, but IS returned.
Since the while() loop checks for content returned, and since http_get
function returns $out_fname even if curl did not return 0, the sa-update
does NOT move to next mirror and the checksum comparison fails.
- the 3.4.0 sa-update did detect this problem and http_get only returned
content when curl exited with status 0
3.
when curl returns 18 and leaves the target file on filesystem, the filename
does not have original file's timestamp.
when file exists, the "-z filename" is appended to the curl command line,
which causes curl to fail, since the stored timestamp is newer.
the "-z" documentation said it fetches file modified later or
before the given time, which we don't apparently want but:
the "-z" seems to cause If-Modified-Since: header to be appended into the
request, which means it only fetches files newer than which we already have.
According to this, I believe that the "-z" option for CURL should be
dropped.
>>On 20.09.18 16:05, Matus UHLAR - fantomas wrote:
>>>I looked at update times and they are different each day - debian script
>>>sleeps random number of seconds (up to one hour) in order to lower the
>>>impact at mirror servers.
>>>
>>>I have removed the "--fail" option from curl and will look at error message
>>>if there's any.
>>>
>>>I'll keep you updated and will fill bugreport if I'm able to find out
>>>anything useful.
On 08.10.18 16:43, Matus UHLAR - fantomas wrote:
>I was able to repeat this problem now:
>
># /usr/bin/curl --verbose -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -- http://sa-update.spamassassin.org/1843052.tar.gz
>* Hostname was NOT found in DNS cache
> % Total % Received % Xferd Average Speed Time Time Time Current
> Dload Upload Total Spent Left Speed
> 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Trying 64.142.56.146...
>* Connected to sa-update.spamassassin.org (64.142.56.146) port 80 (#0)
>>GET /1843052.tar.gz HTTP/1.1
>>User-Agent: curl/7.38.0
>>Host: sa-update.spamassassin.org
>>Accept: */*
>>
> 0 0 0 0 0 0 0 0 --:--:-- 0:00:11 --:--:-- 0< HTTP/1.1 200 OK
>< Date: Mon, 08 Oct 2018 14:16:19 GMT
>* Server Apache/2.4.6 (CentOS) is not blacklisted
>< Server: Apache/2.4.6 (CentOS)
>< Last-Modified: Mon, 08 Oct 2018 03:19:20 GMT
>< ETag: "4600c-577af16429e00"
>< Accept-Ranges: bytes
>< Content-Length: 286732
>< Content-Type: application/x-gzip
><
>{ [data not shown]
> 0 280k 0 1 0 0 0 0 --:--:-- 0:00:13 --:--:-- 0* transfer closed with 286731 bytes remaining to read
>* Closing connection 0
>curl: (18) transfer closed with 286731 bytes remaining to read
>
>
># ls -l 1843052.tar.gz
>-rw-r--r-- 1 root root 1 Oct 8 16:16 1843052.tar.gz
>
>look at today's debug log says:
>
>Oct 8 07:12:59.899 [20257] dbg: channel: selected mirror http://sa-update.spamassassin.org
>Oct 8 07:12:59.899 [20257] dbg: http: url: http://sa-update.spamassassin.org/1843052.tar.gz
>Oct 8 07:12:59.899 [20257] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1843052.tar.gz, new
>Oct 8 07:12:59.899 [20257] dbg: util: executable for curl was found at /usr/bin/curl
>Oct 8 07:12:59.899 [20257] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -- http://sa-update.spamassassin.org/1843052.tar.gz
>Oct 8 07:13:15.385 [20257] dbg: http: process [20258], exit status: 4608
>Oct 8 07:13:15.385 [20257] dbg: channel: selected mirror http://sa-update.ena.com
>Oct 8 07:13:15.385 [20257] dbg: http: url: http://sa-update.ena.com/1843052.tar.gz
>Oct 8 07:13:15.385 [20257] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1843052.tar.gz, update
>Oct 8 07:13:15.385 [20257] dbg: util: executable for curl was found at /usr/bin/curl
>Oct 8 07:13:15.385 [20257] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
>Oct 8 07:13:15.889 [20257] dbg: http: process [20272], exit status: 0
>
>This looks that invalid file was downloaded from sa-update.spamassassin.org,
>and while next curl invocation succeeded with exit code 0, the file was not
>overridden:
>
># /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
># ls -l 1843052.tar.gz
>-rw-r--r-- 1 root root 243 Oct 8 16:21 1843052.tar.gz
># /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
># ls -l 1843052.tar.gz
>-rw-r--r-- 1 root root 243 Oct 8 16:21 1843052.tar.gz
># rm 1843052.tar.gz
># /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
># ls -l 1843052.tar.gz
>-rw-r--r-- 1 root root 286732 Oct 8 05:19 1843052.tar.gz
>
>(the file size changed to 243 because of my tests).
>
>further look at logs says that all failed downloads were from
>sa-update.spamassassin.org:
>
>Sep 28 07:43:07.888 [7018] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842077.tar.gz -- http://sa-update.spamassassin.org/1842077.tar.gz
>Sep 28 07:43:21.973 [7018] dbg: http: process [7019], exit status: 4608
>
>Oct 5 06:35:10.552 [29702] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842787.tar.gz -- http://sa-update.spamassassin.org/1842787.tar.gz
>Oct 5 06:35:29.199 [29702] dbg: http: process [29705], exit status: 4608
>
>Oct 7 07:17:37.644 [30424] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843008.tar.gz -- http://sa-update.spamassassin.org/1843008.tar.gz
>Oct 7 07:18:11.394 [30424] dbg: http: process [30427], exit status: 4608
>
>
>btw, when repeating attempts to download from sa-update.spamassassin.org,
>many of them failed.
>
>It looks to me that:
>1. sa-update.spamassassin.org has some rate limiting or problem with tcp/ip
> (accelerator?)
>
>2. the script does NOT remove downloaded file when download fails and curl
> is NOT instructed to do so.
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
Posli tento mail 100 svojim znamim - nech vidia aky si idiot
Send this email to 100 your friends - let them see what an idiot you are
Re: repeated sa-update problems
Posted by Matus UHLAR - fantomas <uh...@fantomas.sk>.
>On 20.09.18 16:05, Matus UHLAR - fantomas wrote:
>>I looked at update times and they are different each day - debian script
>>sleeps random number of seconds (up to one hour) in order to lower the
>>impact at mirror servers.
>>
>>I have removed the "--fail" option from curl and will look at error message
>>if there's any.
>>
>>I'll keep you updated and will fill bugreport if I'm able to find out
>>anything useful.
I was able to repeat this problem now:
# /usr/bin/curl --verbose -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -- http://sa-update.spamassassin.org/1843052.tar.gz
* Hostname was NOT found in DNS cache
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Trying 64.142.56.146...
* Connected to sa-update.spamassassin.org (64.142.56.146) port 80 (#0)
> GET /1843052.tar.gz HTTP/1.1
> User-Agent: curl/7.38.0
> Host: sa-update.spamassassin.org
> Accept: */*
>
0 0 0 0 0 0 0 0 --:--:-- 0:00:11 --:--:-- 0< HTTP/1.1 200 OK
< Date: Mon, 08 Oct 2018 14:16:19 GMT
* Server Apache/2.4.6 (CentOS) is not blacklisted
< Server: Apache/2.4.6 (CentOS)
< Last-Modified: Mon, 08 Oct 2018 03:19:20 GMT
< ETag: "4600c-577af16429e00"
< Accept-Ranges: bytes
< Content-Length: 286732
< Content-Type: application/x-gzip
<
{ [data not shown]
0 280k 0 1 0 0 0 0 --:--:-- 0:00:13 --:--:-- 0* transfer closed with 286731 bytes remaining to read
* Closing connection 0
curl: (18) transfer closed with 286731 bytes remaining to read
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 1 Oct 8 16:16 1843052.tar.gz
look at today's debug log says:
Oct 8 07:12:59.899 [20257] dbg: channel: selected mirror http://sa-update.spamassassin.org
Oct 8 07:12:59.899 [20257] dbg: http: url: http://sa-update.spamassassin.org/1843052.tar.gz
Oct 8 07:12:59.899 [20257] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1843052.tar.gz, new
Oct 8 07:12:59.899 [20257] dbg: util: executable for curl was found at /usr/bin/curl
Oct 8 07:12:59.899 [20257] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -- http://sa-update.spamassassin.org/1843052.tar.gz
Oct 8 07:13:15.385 [20257] dbg: http: process [20258], exit status: 4608
Oct 8 07:13:15.385 [20257] dbg: channel: selected mirror http://sa-update.ena.com
Oct 8 07:13:15.385 [20257] dbg: http: url: http://sa-update.ena.com/1843052.tar.gz
Oct 8 07:13:15.385 [20257] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1843052.tar.gz, update
Oct 8 07:13:15.385 [20257] dbg: util: executable for curl was found at /usr/bin/curl
Oct 8 07:13:15.385 [20257] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
Oct 8 07:13:15.889 [20257] dbg: http: process [20272], exit status: 0
This looks that invalid file was downloaded from sa-update.spamassassin.org,
and while next curl invocation succeeded with exit code 0, the file was not
overridden:
# /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 243 Oct 8 16:21 1843052.tar.gz
# /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 243 Oct 8 16:21 1843052.tar.gz
# rm 1843052.tar.gz
# /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843052.tar.gz -z 1843052.tar.gz -- http://sa-update.ena.com/1843052.tar.gz
# ls -l 1843052.tar.gz
-rw-r--r-- 1 root root 286732 Oct 8 05:19 1843052.tar.gz
(the file size changed to 243 because of my tests).
further look at logs says that all failed downloads were from
sa-update.spamassassin.org:
Sep 28 07:43:07.888 [7018] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842077.tar.gz -- http://sa-update.spamassassin.org/1842077.tar.gz
Sep 28 07:43:21.973 [7018] dbg: http: process [7019], exit status: 4608
Oct 5 06:35:10.552 [29702] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842787.tar.gz -- http://sa-update.spamassassin.org/1842787.tar.gz
Oct 5 06:35:29.199 [29702] dbg: http: process [29705], exit status: 4608
Oct 7 07:17:37.644 [30424] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1843008.tar.gz -- http://sa-update.spamassassin.org/1843008.tar.gz
Oct 7 07:18:11.394 [30424] dbg: http: process [30427], exit status: 4608
btw, when repeating attempts to download from sa-update.spamassassin.org,
many of them failed.
It looks to me that:
1. sa-update.spamassassin.org has some rate limiting or problem with tcp/ip
(accelerator?)
2. the script does NOT remove downloaded file when download fails and curl
is NOT instructed to do so.
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
One OS to rule them all, One OS to find them,
One OS to bring them all and into darkness bind them
Re: repeated sa-update problems
Posted by Matus UHLAR - fantomas <uh...@fantomas.sk>.
>>On 9/20/2018 8:59 AM, Dave Jones wrote:
>>>I will have to check later if someone else can't check today. I am at
>>>a customer location where I don't have good VPN connection out and
>>>will be traveling this evening. I can check tomorrow if it can wait.
>
>On 20.09.18 09:05, Kevin A. McGrail wrote:
>>It can wait. Matus also had the issue hitting my mirror and I know I
>>don't use a CDN.
On 20.09.18 16:05, Matus UHLAR - fantomas wrote:
>I looked at update times and they are different each day - debian script
>sleeps random number of seconds (up to one hour) in order to lower the
>impact at mirror servers.
>
>I have removed the "--fail" option from curl and will look at error message
>if there's any.
>
>I'll keep you updated and will fill bugreport if I'm able to find out
>anything useful.
the problem repeated today
Sep 28 07:43:07.888 [7018] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842077.tar.gz -- http://sa-update.spamassassin.org/1842077.tar.gz
Sep 28 07:43:21.973 [7018] dbg: http: process [7019], exit status: 4608
Sep 28 07:43:21.973 [7018] dbg: channel: selected mirror http://sa-update.space-pro.be
Sep 28 07:43:21.974 [7018] dbg: http: url: http://sa-update.space-pro.be/1842077.tar.gz
Sep 28 07:43:21.974 [7018] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1842077.tar.gz, update
Sep 28 07:43:21.974 [7018] dbg: util: executable for curl was found at /usr/bin/curl
Sep 28 07:43:21.974 [7018] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842077.tar.gz -z 1842077.tar.gz -- http://sa-update.space-pro.be/1842077.tar.gz
Sep 28 07:43:22.304 [7018] dbg: http: process [7041], exit status: 0
Sep 28 07:43:22.305 [7018] dbg: http: url: http://sa-update.space-pro.be/1842077.tar.gz.sha1
Sep 28 07:43:22.305 [7018] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1842077.tar.gz.sha1, new
Sep 28 07:43:22.305 [7018] dbg: util: executable for curl was found at /usr/bin/curl
Sep 28 07:43:22.305 [7018] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842077.tar.gz.sha1 -- http://sa-update.space-pro.be/1842077.tar.gz.sha1
Sep 28 07:43:22.376 [7018] dbg: http: process [7043], exit status: 0
Sep 28 07:43:22.376 [7018] dbg: http: url: http://sa-update.space-pro.be/1842077.tar.gz.asc
Sep 28 07:43:22.377 [7018] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1842077.tar.gz.asc, new
Sep 28 07:43:22.377 [7018] dbg: util: executable for curl was found at /usr/bin/curl
Sep 28 07:43:22.377 [7018] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 -o 1842077.tar.gz.asc -- http://sa-update.space-pro.be/1842077.tar.gz.asc
Sep 28 07:43:22.446 [7018] dbg: http: process [7045], exit status: 0
Sep 28 07:43:22.446 [7018] dbg: sha1: verification wanted: cb1b907b4f590fe24d0744cf60939685d51b3443
Sep 28 07:43:22.446 [7018] dbg: sha1: verification result: 953efe8f531a5a87f6d2d5a65b78b05e55599abc
channel: SHA1 verification failed, channel failed
# ls -lctr --full-time 1842077.*
-rw-r--r-- 1 debian-spamd debian-spamd 1 2018-09-28 07:43:21.967880543 +0200 1842077.tar.gz
-rw-r--r-- 1 debian-spamd debian-spamd 113 2018-09-28 07:43:22.371884772 +0200 1842077.tar.gz.sha1
-rw-r--r-- 1 debian-spamd debian-spamd 819 2018-09-28 07:43:22.443885519 +0200 1842077.tar.gz.asc
# hd 1842077.tar.gz
00000000 1f |.|
00000001
Sep 28 07:43:23 fgt date=2018-09-28,time=07:43:23,devname=xx,devid=xy,logid=0000000013,type=traffic,subtype=forward,level=notice,vd=root,srcip=192.168.1.1,srcport=52411,srcintf="internal",dstip=176.28.55.20,dstport=80,dstintf="wan1",poluuid=9a0df156-900e-51e8-d4d5-7b4de8e07615,sessionid=87366444,proto=6,action=close,policyid=62,policytype=policy,dstcountry="France",srccountry="Reserved",trandisp=snat,transip=195.80.174.159,transport=52411,service="HTTP",duration=1,sentbyte=470,rcvdbyte=327,sentpkt=6,rcvdpkt=4,appcat="unscanned",wanin=111,wanout=150,lanin=150,lanout=111
Sep 28 07:43:23 fgt date=2018-09-28,time=07:43:23,devname=xx,devid=xy,logid=0000000013,type=traffic,subtype=forward,level=notice,vd=root,srcip=192.168.1.1,srcport=52412,srcintf="internal",dstip=176.28.55.20,dstport=80,dstintf="wan1",poluuid=9a0df156-900e-51e8-d4d5-7b4de8e07615,sessionid=87366446,proto=6,action=close,policyid=62,policytype=policy,dstcountry="France",srccountry="Reserved",trandisp=snat,transip=195.80.174.159,transport=52412,service="HTTP",duration=1,sentbyte=425,rcvdbyte=550,sentpkt=6,rcvdpkt=4,appcat="unscanned",wanin=334,wanout=105,lanin=105,lanout=334
Sep 28 07:43:23 fgt date=2018-09-28,time=07:43:23,devname=xx,devid=xy,logid=0000000013,type=traffic,subtype=forward,level=notice,vd=root,srcip=192.168.1.1,srcport=52413,srcintf="internal",dstip=176.28.55.20,dstport=80,dstintf="wan1",poluuid=9a0df156-900e-51e8-d4d5-7b4de8e07615,sessionid=87366448,proto=6,action=close,policyid=62,policytype=policy,dstcountry="France",srccountry="Reserved",trandisp=snat,transip=195.80.174.159,transport=52413,service="HTTP",duration=1,sentbyte=424,rcvdbyte=1272,sentpkt=6,rcvdpkt=4,appcat="unscanned",wanin=1056,wanout=104,lanin=104,lanout=1056
I can of course suspect our fgt firewall from having problems, but logs from
server would be great.
source IP: 195.80.174.159
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
You have the right to remain silent. Anything you say will be misquoted,
then used against you.
Re: repeated sa-update problems
Posted by Matus UHLAR - fantomas <uh...@fantomas.sk>.
>On 9/20/2018 8:59 AM, Dave Jones wrote:
>> I will have to check later if someone else can't check today. I am at
>> a customer location where I don't have good VPN connection out and
>> will be traveling this evening. I can check tomorrow if it can wait.
On 20.09.18 09:05, Kevin A. McGrail wrote:
>It can wait. Matus also had the issue hitting my mirror and I know I
>don't use a CDN.
I looked at update times and they are different each day - debian script
sleeps random number of seconds (up to one hour) in order to lower the
impact at mirror servers.
I have removed the "--fail" option from curl and will look at error message
if there's any.
I'll keep you updated and will fill bugreport if I'm able to find out
anything useful.
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
Micro$oft random number generator: 0, 0, 0, 4.33e+67, 0, 0, 0...
Re: repeated sa-update problems
Posted by "Kevin A. McGrail" <km...@apache.org>.
On 9/20/2018 8:59 AM, Dave Jones wrote:
> I will have to check later if someone else can't check today. I am at
> a customer location where I don't have good VPN connection out and
> will be traveling this evening. I can check tomorrow if it can wait.
It can wait. Matus also had the issue hitting my mirror and I know I
don't use a CDN.
--
Kevin A. McGrail
VP Fundraising, Apache Software Foundation
Chair Emeritus Apache SpamAssassin Project
https://www.linkedin.com/in/kmcgrail - 703.798.0171
Re: repeated sa-update problems
Posted by Dave Jones <da...@apache.org>.
On 9/20/18 7:58 AM, Kevin A. McGrail wrote:
> On 9/20/2018 7:18 AM, Matus UHLAR - fantomas wrote:
>>> On Wed, 5 Sep 2018 10:08:24 +0200 Matus UHLAR - fantomas wrote:
>>>> I (imho too often) get problems when running sa-update (Debian 8, SA
>>>> 3.4.0)
>>>>
>>>> found at /usr/bin/curl Sep 5 07:38:31.810 [16137] dbg:
>>>> http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2
>>>> --connect-timeout 30 --max-time 300 --fail -o 1840016.tar.gz -z
>>>> 1840016.tar.gz -- http://sa-update.secnap.net/1840016.tar.gz Sep 5
>>>> 07:38:33.211 [16137] dbg: http: process [16166], exit status: 0 ...
>>>> Sep 5 07:38:33.799 [16137] dbg: sha1: verification wanted:
>>>> ea88487c6e9cd48fb3e546606eac2effe4a3a91c Sep 5 07:38:33.799 [16137]
>>>> dbg: sha1: verification result:
>>>> 953efe8f531a5a87f6d2d5a65b78b05e55599abc channel: SHA1 verification
>>>> failed, channel failed
>>> ...
>>>> or should I dig into that deeper to find out what happens?
>> On 06.09.18 18:27, RW wrote:
>>> I'd start by editing sa-update and removing the --fail argument to curl.
>> according to curl documentation, it would only cause to output error
>> message
>> instead of the file itself.
>>
>> Is this what you advise me to achieve?
>>
>> ...according to my reading of sa-update, the sa-update selects mirror
>> and only
>> fetches from it. possibility of fetching from multiple mirrors would help
>> here.
>>
> Dave, is secnap one of the mirrors using a CDN?
>
I will have to check later if someone else can't check today. I am at a
customer location where I don't have good VPN connection out and will be
traveling this evening. I can check tomorrow if it can wait.
Re: repeated sa-update problems
Posted by RW <rw...@googlemail.com>.
On Thu, 20 Sep 2018 08:58:07 -0400
Kevin A. McGrail wrote:
> On 9/20/2018 8:35 AM, Matus UHLAR - fantomas wrote:
> > unfortunately, secnap is not the only mirror with which the problem
> > occurs.
> > - is this possible problem with mirrors?
> > - when do mirrors update?
> > - do mirrors updates propagate atomically?
> Dave, is there an issue where DNS is being updated before the mirrors?
It seems unlikely. In the original example there was enough of a sha1
file to provide a 40 character hash and curl downloaded an update file
that was one byte long. I tried running the same command, but with the
version changed by 1 in the URL, and curl didn't create a file at all.
Also IIRC rsync does an atomic rename when a file is added, so the web
server should see a complete file or no file.
Re: repeated sa-update problems
Posted by "Kevin A. McGrail" <km...@apache.org>.
On 9/20/2018 8:35 AM, Matus UHLAR - fantomas wrote:
> unfortunately, secnap is not the only mirror with which the problem
> occurs.
> - is this possible problem with mirrors?
> - when do mirrors update?
> - do mirrors updates propagate atomically?
Dave, is there an issue where DNS is being updated before the mirrors?
He's hitting an issue on PCCC where I know I don't use a CDN.
Matus, try moving your cron job an hour later. I'm wondering if you are
hitting an atomic update issue.
> perhaps the sa-update could be changed to try with more mirrors?
If you open a bug and can take a whack at the code, I'd +1 it.
--
Kevin A. McGrail
VP Fundraising, Apache Software Foundation
Chair Emeritus Apache SpamAssassin Project
https://www.linkedin.com/in/kmcgrail - 703.798.0171
Re: repeated sa-update problems
Posted by Matus UHLAR - fantomas <uh...@fantomas.sk>.
>>> On Wed, 5 Sep 2018 10:08:24 +0200 Matus UHLAR - fantomas wrote:
>>>> I (imho too often) get problems when running sa-update (Debian 8, SA
>>>> 3.4.0)
>>>>
>>>
>>>> found at /usr/bin/curl Sep 5 07:38:31.810 [16137] dbg:
>>>> http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2
>>>> --connect-timeout 30 --max-time 300 --fail -o 1840016.tar.gz -z
>>>> 1840016.tar.gz -- http://sa-update.secnap.net/1840016.tar.gz Sep 5
>>>> 07:38:33.211 [16137] dbg: http: process [16166], exit status: 0 ...
>>>> Sep 5 07:38:33.799 [16137] dbg: sha1: verification wanted:
>>>> ea88487c6e9cd48fb3e546606eac2effe4a3a91c Sep 5 07:38:33.799 [16137]
>>>> dbg: sha1: verification result:
>>>> 953efe8f531a5a87f6d2d5a65b78b05e55599abc channel: SHA1 verification
>>>> failed, channel failed
>>> ...
>>>> or should I dig into that deeper to find out what happens?
>> On 06.09.18 18:27, RW wrote:
>>> I'd start by editing sa-update and removing the --fail argument to curl.
>On 9/20/2018 7:18 AM, Matus UHLAR - fantomas wrote:
>> according to curl documentation, it would only cause to output error
>> message
>> instead of the file itself.
>>
>> Is this what you advise me to achieve?
>>
>> ...according to my reading of sa-update, the sa-update selects mirror
>> and only
>> fetches from it. possibility of fetching from multiple mirrors would help
>> here.
On 20.09.18 07:58, Kevin A. McGrail wrote:
>Dave, is secnap one of the mirrors using a CDN?
unfortunately, secnap is not the only mirror with which the problem occurs.
Sep 20 07:25:34.589 [30532] dbg: http: url: http://www.sa-update.pccc.com/1841300.tar.gz.asc
Sep 20 07:25:34.589 [30532] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1841300.tar.gz.asc, new
Sep 20 07:25:34.589 [30532] dbg: util: executable for curl was found at /usr/bin/curl
Sep 20 07:25:34.589 [30532] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1841300.tar.gz.asc -- http://www.sa-update.pccc.com/1841300.tar.gz.asc
Sep 20 07:25:34.823 [30532] dbg: http: process [30569], exit status: 0
Sep 20 07:25:34.824 [30532] dbg: sha1: verification wanted: 37342f104bce02b8ede7a769b3c23ddc0b02dc3d
Sep 20 07:25:34.824 [30532] dbg: sha1: verification result: 7a65e9db86acc2901a90be825d1efc0990f8c020
channel: SHA1 verification failed, channel failed
it also is not the only one roblem that occurs, the
"channel: could not find working mirror, channel failed"
happens quite often too.
I have tried to remove the "--fail" option so maybe the output will help me
a bit. Otoh, my questions still apply:
- is this possible problem with mirrors?
- when do mirrors update?
- do mirrors updates propagate atomically?
perhaps the sa-update could be changed to try with more mirrors?
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
"To Boot or not to Boot, that's the question." [WD1270 Caviar]
Re: repeated sa-update problems
Posted by "Kevin A. McGrail" <km...@apache.org>.
On 9/20/2018 7:18 AM, Matus UHLAR - fantomas wrote:
>> On Wed, 5 Sep 2018 10:08:24 +0200 Matus UHLAR - fantomas wrote:
>>> I (imho too often) get problems when running sa-update (Debian 8, SA
>>> 3.4.0)
>>>
>>
>>> found at /usr/bin/curl Sep 5 07:38:31.810 [16137] dbg:
>>> http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2
>>> --connect-timeout 30 --max-time 300 --fail -o 1840016.tar.gz -z
>>> 1840016.tar.gz -- http://sa-update.secnap.net/1840016.tar.gz Sep 5
>>> 07:38:33.211 [16137] dbg: http: process [16166], exit status: 0 ...
>>> Sep 5 07:38:33.799 [16137] dbg: sha1: verification wanted:
>>> ea88487c6e9cd48fb3e546606eac2effe4a3a91c Sep 5 07:38:33.799 [16137]
>>> dbg: sha1: verification result:
>>> 953efe8f531a5a87f6d2d5a65b78b05e55599abc channel: SHA1 verification
>>> failed, channel failed
>> ...
>>> or should I dig into that deeper to find out what happens?
>
> On 06.09.18 18:27, RW wrote:
>> I'd start by editing sa-update and removing the --fail argument to curl.
>
> according to curl documentation, it would only cause to output error
> message
> instead of the file itself.
>
> Is this what you advise me to achieve?
>
> ...according to my reading of sa-update, the sa-update selects mirror
> and only
> fetches from it. possibility of fetching from multiple mirrors would help
> here.
>
Dave, is secnap one of the mirrors using a CDN?
--
Kevin A. McGrail
VP Fundraising, Apache Software Foundation
Chair Emeritus Apache SpamAssassin Project
https://www.linkedin.com/in/kmcgrail - 703.798.0171
Re: repeated sa-update problems
Posted by Matus UHLAR - fantomas <uh...@fantomas.sk>.
>On Wed, 5 Sep 2018 10:08:24 +0200 Matus UHLAR - fantomas wrote:
>> I (imho too often) get problems when running sa-update (Debian 8, SA
>> 3.4.0)
>>
>
>> found at /usr/bin/curl Sep 5 07:38:31.810 [16137] dbg:
>> http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2
>> --connect-timeout 30 --max-time 300 --fail -o 1840016.tar.gz -z
>> 1840016.tar.gz -- http://sa-update.secnap.net/1840016.tar.gz Sep 5
>> 07:38:33.211 [16137] dbg: http: process [16166], exit status: 0 ...
>> Sep 5 07:38:33.799 [16137] dbg: sha1: verification wanted:
>> ea88487c6e9cd48fb3e546606eac2effe4a3a91c Sep 5 07:38:33.799 [16137]
>> dbg: sha1: verification result:
>> 953efe8f531a5a87f6d2d5a65b78b05e55599abc channel: SHA1 verification
>> failed, channel failed
>...
>> or should I dig into that deeper to find out what happens?
On 06.09.18 18:27, RW wrote:
>I'd start by editing sa-update and removing the --fail argument to curl.
according to curl documentation, it would only cause to output error message
instead of the file itself.
Is this what you advise me to achieve?
...according to my reading of sa-update, the sa-update selects mirror and only
fetches from it. possibility of fetching from multiple mirrors would help
here.
--
Matus UHLAR - fantomas, uhlar@fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
Microsoft dick is soft to do no harm
Re: repeated sa-update problems
Posted by RW <rw...@googlemail.com>.
On Wed, 5 Sep 2018 10:08:24 +0200
Matus UHLAR - fantomas wrote:
> Hello,
>
> I (imho too often) get problems when running sa-update (Debian 8, SA
> 3.4.0)
>
> found at /usr/bin/curl Sep 5 07:38:31.810 [16137] dbg:
> http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2
> --connect-timeout 30 --max-time 300 --fail -o 1840016.tar.gz -z
> 1840016.tar.gz -- http://sa-update.secnap.net/1840016.tar.gz Sep 5
> 07:38:33.211 [16137] dbg: http: process [16166], exit status: 0 ...
> Sep 5 07:38:33.799 [16137] dbg: sha1: verification wanted:
> ea88487c6e9cd48fb3e546606eac2effe4a3a91c Sep 5 07:38:33.799 [16137]
> dbg: sha1: verification result:
> 953efe8f531a5a87f6d2d5a65b78b05e55599abc channel: SHA1 verification
> failed, channel failed
...
> or should I dig into that deeper to find out what happens?
I'd start by editing sa-update and removing the --fail argument to curl.