Bug 7074 - sa-update failing because curl returns exit code 13
Summary: sa-update failing because curl returns exit code 13
Status: RESOLVED INVALID
Alias: None
Product: Spamassassin
Classification: Unclassified
Component: sa-update (show other bugs)
Version: 3.4.0
Hardware: PC Linux
: P2 major
Target Milestone: Undefined
Assignee: SpamAssassin Developer Mailing List
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-08-14 17:20 UTC by Marty Phelan
Modified: 2014-09-30 14:19 UTC (History)
2 users (show)


Attachment Type Modified Status Actions Submitter/CLA Status
properly report a crashed spawned process patch None Mark Martinec [HasCLA]
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Marty Phelan 2014-08-14 17:20:20 UTC 
Cannot perform sa-update for system. Noticed because daily cron job sent warning email:

/etc/cron.daily/spamassassin:
error: no mirror data available for channel updates.spamassassin.org
channel: MIRRORED.BY file contents were missing, channel failed
sa-update failed for unknown reasons

Environment:
Ubuntu 14.04 (up-to-date)
Spamassassin 3.4.0

tried running sa-update as debian-spamd:
debian-spamd@venus:~$ sa-update --gpghomedir /var/lib/spamassassin/sa-update-keys -D
Output (abbrievated):
...
Aug 14 09:09:42.989 [10281] dbg: channel: no mirror file /var/lib/spamassassin/3.004000/updates_spamassassin_org/MIRRORED.BY, will fetch it
Aug 14 09:09:42.989 [10281] dbg: channel: DNS lookup on mirrors.updates.spamassassin.org
Aug 14 09:09:42.990 [10281] dbg: http: url: http://spamassassin.apache.org/updates/MIRRORED.BY
Aug 14 09:09:42.990 [10281] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/MIRRORED.BY, new
Aug 14 09:09:42.990 [10281] dbg: util: executable for curl was found at /usr/bin/curl
Aug 14 09:09:42.990 [10281] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o MIRRORED.BY -- http://spamassassin.apache.org/updates/MIRRORED.BY
Aug 14 09:09:42.996 [10281] dbg: http: process [10282], exit status: 13
Aug 14 09:09:42.996 [10281] dbg: channel: no mirror data available for channel updates.spamassassin.org from http://spamassassin.apache.org/updates/MIRRORED.BY
error: no mirror data available for channel updates.spamassassin.org
channel: MIRRORED.BY file contents were missing, channel failed
Aug 14 09:09:42.996 [10281] dbg: generic: cleaning up temporary directory/files
Aug 14 09:09:42.996 [10281] dbg: generic: cleaning directory /tmp/.spamassassin10281OjrLbxtmp
Aug 14 09:09:42.996 [10281] dbg: diag: updates complete, exiting with code 4

Manually ran curl command successfully:
cd /var/lib/spamassassin/3.004000/updates_spamassassin_org
/usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o MIRRORED.BY -- http://spamassassin.apache.org/updates/MIRRORED.BY

Then tried sa-update again and got:
...
Aug 14 09:17:03.564 [10396] dbg: channel: file /var/lib/spamassassin/3.004000/updates_spamassassin_org/MIRRORED.BY is too old, refreshing mirrors file
Aug 14 09:17:03.564 [10396] dbg: channel: DNS lookup on mirrors.updates.spamassassin.org
Aug 14 09:17:03.565 [10396] dbg: http: url: http://spamassassin.apache.org/updates/MIRRORED.BY
Aug 14 09:17:03.565 [10396] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/MIRRORED.BY, replace
Aug 14 09:17:03.565 [10396] dbg: util: executable for curl was found at /usr/bin/curl
Aug 14 09:17:03.565 [10396] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o MIRRORED.BY -- http://spamassassin.apache.org/updates/MIRRORED.BY
Aug 14 09:17:03.571 [10396] dbg: http: process [10397], exit status: 13
Aug 14 09:17:03.571 [10396] dbg: channel: no mirror data available for channel updates.spamassassin.org from http://spamassassin.apache.org/updates/MIRRORED.BY
error: unable to refresh mirrors file for channel updates.spamassassin.org, using old file
Aug 14 09:17:03.571 [10396] dbg: channel: reading MIRRORED.BY file /var/lib/spamassassin/3.004000/updates_spamassassin_org/MIRRORED.BY
Aug 14 09:17:03.571 [10396] dbg: channel: parsing MIRRORED.BY file for channel updates.spamassassin.org
Aug 14 09:17:03.571 [10396] dbg: channel: found mirror http://sa-update.dnswl.org/ weight=1
Aug 14 09:17:03.571 [10396] dbg: channel: found mirror http://www.sa-update.pccc.com/ weight=5
Aug 14 09:17:03.572 [10396] dbg: channel: found mirror http://sa-update.secnap.net/ weight=5
Aug 14 09:17:03.572 [10396] dbg: channel: found mirror http://sa-update.space-pro.be/ weight=1
Aug 14 09:17:03.572 [10396] dbg: channel: selected mirror http://sa-update.secnap.net
Aug 14 09:17:03.572 [10396] dbg: http: url: http://sa-update.secnap.net/1613764.tar.gz
Aug 14 09:17:03.572 [10396] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1613764.tar.gz, new
Aug 14 09:17:03.572 [10396] dbg: util: executable for curl was found at /usr/bin/curl
Aug 14 09:17:03.572 [10396] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1613764.tar.gz -- http://sa-update.secnap.net/1613764.tar.gz
Aug 14 09:17:03.578 [10396] dbg: http: process [10398], exit status: 13
Aug 14 09:17:03.578 [10396] dbg: channel: selected mirror http://sa-update.dnswl.org
Aug 14 09:17:03.578 [10396] dbg: http: url: http://sa-update.dnswl.org/1613764.tar.gz
Aug 14 09:17:03.578 [10396] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1613764.tar.gz, new
Aug 14 09:17:03.578 [10396] dbg: util: executable for curl was found at /usr/bin/curl
Aug 14 09:17:03.578 [10396] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1613764.tar.gz -- http://sa-update.dnswl.org/1613764.tar.gz
Aug 14 09:17:03.583 [10396] dbg: http: process [10399], exit status: 13
Aug 14 09:17:03.583 [10396] dbg: channel: selected mirror http://www.sa-update.pccc.com
Aug 14 09:17:03.583 [10396] dbg: http: url: http://www.sa-update.pccc.com/1613764.tar.gz
Aug 14 09:17:03.583 [10396] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1613764.tar.gz, new
Aug 14 09:17:03.584 [10396] dbg: util: executable for curl was found at /usr/bin/curl
Aug 14 09:17:03.584 [10396] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1613764.tar.gz -- http://www.sa-update.pccc.com/1613764.tar.gz
Aug 14 09:17:03.588 [10396] dbg: http: process [10400], exit status: 13
Aug 14 09:17:03.589 [10396] dbg: channel: selected mirror http://sa-update.space-pro.be
Aug 14 09:17:03.589 [10396] dbg: http: url: http://sa-update.space-pro.be/1613764.tar.gz
Aug 14 09:17:03.589 [10396] dbg: http: downloading to: /var/lib/spamassassin/3.004000/updates_spamassassin_org/1613764.tar.gz, new
Aug 14 09:17:03.589 [10396] dbg: util: executable for curl was found at /usr/bin/curl
Aug 14 09:17:03.589 [10396] dbg: http: /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o 1613764.tar.gz -- http://sa-update.space-pro.be/1613764.tar.gz
Aug 14 09:17:03.595 [10396] dbg: http: process [10401], exit status: 13
channel: could not find working mirror, channel failed
Aug 14 09:17:03.596 [10396] dbg: generic: cleaning up temporary directory/files
Aug 14 09:17:03.596 [10396] dbg: generic: cleaning directory /tmp/.spamassassin10396koqaqjtmp
Aug 14 09:17:03.596 [10396] dbg: diag: updates complete, exiting with code 4

Appears that running curl within sa-update is failing for some reason.

Result is: cannot update spamassassin rules.
Comment 1 Mark Martinec 2014-08-14 17:46:17 UTC 
exit status: 13
13) SIGPIPE

Try running the same command manually:

  /usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o MIRRORED.BY -- http://spamassassin.apache.org/updates/MIRRORED.BY

It is perhaps writing anything to stdout? (it shouldn't, should just produce
the file MIRRORED.BY in a currect directory).

Does sa-update work correctly when running interactively, but fails in cron?
Comment 2 Karsten Bräckelmann 2014-08-14 21:33:17 UTC 
(In reply to Marty Phelan from comment #0)
> Aug 14 09:09:42.990 [10281] dbg: http: /usr/bin/curl -s -L -O --remote-time
> -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o MIRRORED.BY
> -- http://spamassassin.apache.org/updates/MIRRORED.BY
> Aug 14 09:09:42.996 [10281] dbg: http: process [10282], exit status: 13

(In reply to Mark Martinec from comment #1)
> 13) SIGPIPE

That's the external 'curl' process's exit status, not a signal. From the curl man page, section Exit Codes:

  13  FTP  weird PASV reply, Curl couldn't parse the reply sent to the
      PASV request.

Why does curl return an FTP related exit code for an HTTP request?


(In reply to Marty Phelan from comment #0)
> Manually ran curl command successfully:

What user did you do the manual curl command as?

I note that all 6 curl calls done by sa-update fail. The one manual invocation succeeds.
Comment 3 Mark Martinec 2014-08-14 23:08:36 UTC 
> (In reply to Mark Martinec from comment #1)
> > 13) SIGPIPE
> 
> That's the external 'curl' process's exit status, not a signal. From the
> curl man page, section Exit Codes:

Unfortunately not so. The process exit status as reported by sa-update
is sloppy, it shows the complete '$?' which is a complete 16-bit
process exit status (the low byte is a signal, the high byte is a
proper exit status code if process exited and not signalled).
It should have been processed through WTERMSIG by
Mail::SpamAssassin::Util::exit_status_str(), but sa-update hasn't
been converted yet to use that and be more human-friendly.
Comment 4 Karsten Bräckelmann 2014-08-14 23:25:35 UTC 
(In reply to Mark Martinec from comment #3)
> Unfortunately not so. The process exit status as reported by sa-update
> is sloppy, it shows the complete '$?' which is a complete 16-bit
> process exit status (the low byte is a signal, the high byte is a
> proper exit status code if process exited and not signalled).

Ugh, I see. Thanks, Mark.

Marty, please disregard the first part of comment 2.
Comment 5 Marty Phelan 2014-08-15 01:56:45 UTC 
In reply to Comment #2:

>Try running the same command manually:
>/usr/bin/curl -s -L -O --remote-time -g --max-redirs 2 --connect-timeout 30 --max-time 300 --fail -o MIRRORED.BY -- http://spamassassin.apache.org/updates/MIRRORED.BY
>It is perhaps writing anything to stdout? 
NO
 
>(it shouldn't, should just produce the file MIRRORED.BY in a currect directory). 
CORRECT. It did create file MIRRORED.BY

>Does sa-update work correctly when running interactively, 
NO. sa-update does NOT work interactively. With the -D option it produced the output shown in original bug report (line 13 on).

>but fails in cron?
YES. Also fails in cron. Emails error message:
error: no mirror data available for channel updates.spamassassin.org
channel: MIRRORED.BY file contents were missing, channel failed
sa-update failed for unknown reasons
Comment 6 Mark Martinec 2014-09-30 12:21:13 UTC 
Created attachment 5241 [details]
properly report a crashed spawned process

Distinguish an exited from a crashed spawned process
in error reporting by sa-update.

Previously:
  http: (curl) GET http://spamassassin.apache.org/updates/MIRRORED.BY, FAILED, status: 13

Now:
  http: (curl) GET http://spamassassin.apache.org/updates/MIRRORED.BY, FAILED, status: DIED, signal 13 (000d)
Comment 7 Mark Martinec 2014-09-30 12:23:19 UTC 
Bug 7074, sa-update: improved error reporting of a failed spawned process
  Sending sa-update.raw
Committed revision 1628417.


Note that this only improves error reporting.

The original reported problem remains a mystery.
Apparently others are unable to reproduce a SIGPIPE failure in curl.
Comment 8 Mark Martinec 2014-09-30 14:08:37 UTC 
Apparently a bug in curl, fixed on 2014-05-05 :

curl-7.38.0 / CHANGES:

Daniel Stenberg (5 May 2014)
- [Jeff King brought this change]

  curl_multi_cleanup: ignore SIGPIPE better

  When looping and closing each individual connection left open, the
  SIGPIPE ignoring was not done and could thus lead to death by signal 13.

  Bug: http://thread.gmane.org/gmane.comp.version-control.git/238242
Comment 9 Kevin A. McGrail 2014-09-30 14:19:46 UTC 
Good find!  Marking as invalid since it's a bug in curl.