mget fails for large files over slow internet

[notmatt]

Attempting to download a large (2GB) file over slow internet yielded this:

$ mget ~~/stor/big.tgz -O big.tgz
big.tgz [===========>                           ]  32% 765.19MB 476.60KB/s 55m51smget: RequestExpiredError: Date header Fri, 21 Nov 2014 01:45:31 GMT is too old

Where 01:45:31 is approximately the time of the original request. This occurs reliably for me, though at varying times after the initial request.

[nfitch]

@notmatt repro'd with -v to get the logs:

[2014-11-21T18:07:48.221Z] DEBUG: mget/MantaClient/18983 on Brandt.local (/usr/local/lib/node_modules/manta/lib/client.js:670 in get): get: entered (req_id=91e70f55-ce8f-4ccf-a542-6d8239ea358d, id=91e70f55-ce8f-4ccf-a542-6d8239ea358d, query={})
    path: /Joyent_Dev/stor/builds/usbheadnode/master-20140213T090606Z/usbheadnode/coal-master-20140213T090606Z-g750ef04-4gb.tgz
    --
    headers: {
      "accept": "*/*",
      "date": "Fri, 21 Nov 2014 18:07:48 GMT",
      "x-request-id": "91e70f55-ce8f-4ccf-a542-6d8239ea358d"
    }
[2014-11-21T18:07:48.250Z] TRACE: mget/MantaClient/18983 on Brandt.local (/usr/local/lib/node_modules/manta/node_modules/restify/lib/clients/http_client.js:251 in rawRequest): request sent
    GET /Joyent_Dev/stor/builds/usbheadnode/master-20140213T090606Z/usbheadnode/coal-master-20140213T090606Z-g750ef04-4gb.tgz HTTP/1.1
    Host: us-east.manta.joyent.com
    accept: */*
    date: Fri, 21 Nov 2014 18:07:48 GMT
    x-request-id: 91e70f55-ce8f-4ccf-a542-6d8239ea358d
    authorization: Signature keyId="...",algorithm="rsa-sha1",signature="jNhsq...z0O2mw=="
    user-agent: restify/2.8.0 (x64-darwin; v8/3.14.5.9; OpenSSL/1.0.1h) node/0.10.29
    accept-version: ~1.0
[2014-11-21T18:07:49.201Z] TRACE: mget/MantaClient/18983 on Brandt.local (/usr/local/lib/node_modules/manta/node_modules/restify/lib/clients/http_client.js:151 in onResponse): Response received (client_res={})
    HTTP/1.1 200 OK
    etag: bcd12026-4222-6a66-f327-8a84876a5eee
    last-modified: Thu, 13 Feb 2014 09:22:43 GMT
    accept-ranges: bytes
    content-type: application/octet-stream
    content-md5: WvFcDJ9yaPZOfqrLvEumjg==
    content-length: 2438049799
    durability-level: 2
    date: Fri, 21 Nov 2014 18:07:49 GMT
    server: Manta
    x-request-id: 91e70f55-ce8f-4ccf-a542-6d8239ea358d
    x-response-time: 11
    x-server-name: 511ea59e-2a4a-486b-9258-ef59016d064d
    connection: keep-alive
[2014-11-21T18:14:00.774Z] TRACE: mget/MantaClient/18983 on Brandt.local (/usr/local/lib/node_modules/manta/node_modules/restify/lib/clients/http_client.js:251 in rawRequest): request sent
    GET /Joyent_Dev/stor/builds/usbheadnode/master-20140213T090606Z/usbheadnode/coal-master-20140213T090606Z-g750ef04-4gb.tgz HTTP/1.1
    Host: us-east.manta.joyent.com
    accept: */*
    date: Fri, 21 Nov 2014 18:07:48 GMT
    x-request-id: 91e70f55-ce8f-4ccf-a542-6d8239ea358d
    authorization: Signature keyId="...",algorithm="rsa-sha1",signature="jNhsq...z0O2mw=="
    user-agent: restify/2.8.0 (x64-darwin; v8/3.14.5.9; OpenSSL/1.0.1h) node/0.10.29
    accept-version: ~1.0
    if-match: bcd12026-4222-6a66-f327-8a84876a5eee
    range: bytes=213671976-2438049799
[2014-11-21T18:14:01.719Z] TRACE: mget/MantaClient/18983 on Brandt.local (/usr/local/lib/node_modules/manta/node_modules/restify/lib/clients/http_client.js:151 in onResponse): Response received (client_res={})
    HTTP/1.1 400 Bad Request
    content-type: application/json
    content-length: 111
    content-md5: hvwCc4WI+h7kQk9rTu6ixQ==
    date: Fri, 21 Nov 2014 18:14:01 GMT
    server: Manta
    x-request-id: 91e70f55-ce8f-4ccf-a542-6d8239ea358d
    x-response-time: 3
    x-server-name: c84b3cab-1c20-4566-a880-0e202b6b63dd
    connection: keep-alive
[2014-11-21T18:14:01.725Z] DEBUG: mget/MantaClient/18983 on Brandt.local (/usr/local/lib/node_modules/manta/lib/client.js:678): get: error (req_id=91e70f55-ce8f-4ccf-a542-6d8239ea358d)
    InvalidHeaderError: Authorization header invalid: clock skew of 373.674s was greater than 300s
        at ClientRequest.onResponse (/usr/local/lib/node_modules/manta/node_modules/restify/lib/clients/http_client.js:157:26)
        at ClientRequest.g (events.js:180:16)
        at ClientRequest.emit (events.js:95:17)
        at HTTPParser.parserOnIncomingClient (http.js:1688:21)
        at HTTPParser.parserOnHeadersComplete [as onHeadersComplete] (http.js:121:23)
        at CleartextStream.socketOnData (http.js:1583:20)
        at CleartextStream.read [as _read] (tls.js:511:12)
        at CleartextStream.Readable.read (_stream_readable.js:323:10)
        at EncryptedStream.write [as _write] (tls.js:366:25)
        at doWrite (_stream_writable.js:226:10)
    --
    path: /Joyent_Dev/stor/builds/usbheadnode/master-20140213T090606Z/usbheadnode/coal-master-20140213T090606Z-g750ef04-4gb.tgz
mget: InvalidHeaderError: Authorization header invalid: clock skew of 373.674s was greater than 300s

A few things to point out:

1. The request at time 2014-11-21T18:14:00.774Z is using the date header Fri, 21 Nov 2014 18:07:48 GMT (the same as for the request at 2014-11-21T18:07:48.250Z)
2. The request at time 2014-11-21T18:14:00.774Z is using the same signature as the request at 2014-11-21T18:07:48.250Z.
3. It is a range GET request.

[bahamat]

I've been really desiring a --continue-at (like curl has) for mget.

In the mean time I've been using the following script as a wrapper for mget when downloading large files. This helps alleviate the frustration when transfers get interrupted, but does nothing to help the root cause.

#!/bin/bash

MANTA_FILE=$1
LOCAL_FILE=$(basename $1)

[[ -f ${LOCAL_FILE} ]] && R=-H && RANGE="Range: bytes=$(stat -f %z ${LOCAL_FILE})-"

mget $R "${RANGE}" ${MANTA_FILE} >> ${LOCAL_FILE}

[bahamat]

Filed internally as MANTA-2546.

[dwlf]

https://smartos.org/bugview/MANTA-2546

[bahamat]

Fixed in commit 9327891.