more reliable retries and fallback mirror usage - #1336 by wilzbach · Pull Request #1339 · dlang/dub

wilzbach · 2018-01-15T02:49:41Z

See #1336
I'm wondering why 435fd1c#diff-ce350ca917a3ebde71db3a122988b8ba didn't help (it's part of 2.077).

dlang-bot · 2018-01-15T02:49:42Z

Thanks for your pull request, @wilzbach!

wilzbach · 2018-01-15T04:23:18Z

On Travis two jobs even failed with this:

[INFO] Building /home/travis/build/dlang/dub/test/issue502-root-import/...
Fetching gitcompatibledubpackage 1.0.4 (getting selected version)...
ZipException: no end record
[ERROR] Build failure.

https://travis-ci.org/dlang/dub/jobs/328895076

So apparently this doesn't fix the issue :/

wilzbach · 2018-01-19T04:39:58Z

source/dub/dub.d

+				logDiagnostic("Placing to %s...", placement.toNativeString());
+				return m_packageManager.storeFetchedPackage(path, pinfo, dstpath);
+			} catch (ZipException e) {
+				logInfo("Failed to extract zip archive for %s %s...", packageId, ver);


This isn't the best behavior as the PackageManager fallbacks will never be tried if the main registry returns invalid zips. However, this would require refactoring their interface a bit and I wasn't sure whether this is wanted. In any case, this should already be an measureable improvement (see the test) as it will restart the download when the registry / GH returned invalid data.

Packages are downloaded directly from GH though, at least that should be the case.
https://github.com/dlang/dub-registry/blob/fe18df23b32f602a7579816a801a8a4e98346b5c/source/dubregistry/web.d#L177-L187

wilzbach · 2018-01-24T20:07:00Z

This is finally passing on the CIs. It was a bit tricky to add a test for ZipException, but CodeCov shows that mocking the registry works.

MartinNowak · 2018-01-24T20:51:45Z

This seems to work very much on the symptom side of things. Why do we end up silently with corrupted zip packages in the first place? Maybe sth. wrong with std.net.curl.download that doesn't throw an error?

wilzbach · 2018-01-24T21:12:30Z

This seems to work very much on the symptom side of things.

Well, the errors are pretty random and spurious, so it looks like the network stream gets interrupted.
Also I don't know how to reproduce them locally as I only see them from time to time on a CI.
However, the point is that random CI failures are annoying and a simple retry-loop should fix most of the problems for the next release and gives us time to dig into this.

Why do we end up silently with corrupted zip packages in the first place?

If I would know, I wouldn't have proposed this workaround for now.
Maybe instead of digging into this and investing time into the old std.net.curl, we should simply start deploying/using the nonet (aka vibe.d) build?

MartinNowak · 2018-01-27T12:27:42Z

I'd suggest to checksum the packages, but GH apparently rebuild those archives from time to time.
It'd also be possible that we're looking at corruptions on GH's side.

If it's simply an interrupted transfer, then it should be feasible to reproduce this in a test case, e.g. through a proxy.

Maybe instead of digging into this and investing time into the old std.net.curl, we should simply start deploying/using the nonet (aka vibe.d) build?

Not until vibe-core is stable enough to replace the libevent dependency. I've checked std.net.curl.download and couldn't see anything wrong, it's just a thin wrapper around curl_easy_perform.
https://github.com/dlang/phobos/blob/fd3ae774b802a43f2f700b708f53351d07318621/std/net/curl.d#L406-L408
Also vibe's inet.urltransfer.download is fairly simply itself and doesn't handle certain issues (e.g. timeouts), and std.net.curl's bad reputation is mostly based on resolved problems. But as with anything curl (as opposed to wget), you need to explicitly configure lots of parameters.

MartinNowak · 2018-01-27T12:30:12Z

I'm wondering why 435fd1c#diff-ce350ca917a3ebde71db3a122988b8ba didn't help (it's part of 2.077).

Because that retries downloads, i.e. supplier.fetchPackage but not the unpacking that follows that.

wilzbach · 2018-01-27T13:27:21Z

I'd suggest to checksum the packages, but GH apparently rebuild those archives from time to time.
It'd also be possible that we're looking at corruptions on GH's side.

If it's simply an interrupted transfer, then it should be feasible to reproduce this in a test case, e.g. through a proxy.

I already added a simple test registry based on Vibe.d in this PR that either serves a valid or invalid zip. We can probably also test interrupted downloads with this, but I'm not sure what's the best way to simulate this. Should we implement our own file serving (for a specific version) and sleep for 50ms after every n bytes? Or is there more to it?

MartinNowak · 2018-01-27T16:48:32Z

BTW, we should finish support for file:// package suppliers (

dub/source/dub/packagesupplier.d

Line 89 in 785a0b2

class FileSystemPackageSupplier : PackageSupplier {

).

MartinNowak · 2018-01-27T17:43:28Z

Here we go,

router.get("/packages/gitcompatibledubpackage/1.0.2.zip", (req, res) @trusted {
    res.writeBody("", HTTPStatus.internalServerError);
});

$ curl localhost:1234/packages/gitcompatibledubpackage/1.0.2.zip                                                                                                                       
$ curl -fsSL localhost:1234/packages/gitcompatibledubpackage/1.0.2.zip                                                                                                                
curl: (22) The requested URL returned error: 500 Internal Server Error

OK, curl only fails with -f.

$ ./bin/dub fetch gitcompatibledubpackage --version=1.0.2 --skip-registry=all --registry=http://localhost:1234/ --vverbose
Refreshing local packages (refresh existing: true)...
Looking for local package map at /var/lib/dub/packages/local-packages.json
Looking for local package map at /home/dawg/.dub/packages/local-packages.json
Try to load local package map at /home/dawg/.dub/packages/local-packages.json
iterating dir /home/dawg/.dub/packages/
...
Determined package version using GIT: dub 1.7.1-beta.1+commit.34.gcdf18e3
Downloading metadata for gitcompatibledubpackage
Getting from http://localhost:1234/packages/gitcompatibledubpackage.json
Getting http://localhost:1234/packages/gitcompatibledubpackage.json...
Fetching gitcompatibledubpackage 1.0.2...
Acquiring package zip file
Downloading from 'http://localhost:1234/packages/gitcompatibledubpackage/1.0.2.zip'
Storing http://localhost:1234/packages/gitcompatibledubpackage/1.0.2.zip...
Placing to /home/dawg/.dub/packages/...
Placing package 'gitcompatibledubpackage' version '1.0.2' to location '/home/dawg/.dub/packages/gitcompatibledubpackage-1.0.2/gitcompatibledubpackage' from file '/tmp/gitcompatibledubpackage-0c8f66bd-cd98-4a84-819c-f9f06cc8180b.zip'
Opening file /tmp/gitcompatibledubpackage-0c8f66bd-cd98-4a84-819c-f9f06cc8180b.zip
rawRead must take a non-empty buffer
Full exception: object.Exception@/usr/include/dmd/phobos/std/stdio.d(972): rawRead must take a non-empty buffer
----------------
/usr/include/dmd/phobos/std/stdio.d:972 @safe ubyte[] std.stdio.File.rawRead!(ubyte).rawRead(ubyte[]) [0x8851dc]
source/dub/internal/vibecompat/core/file.d:46 @trusted void dub.internal.vibecompat.core.file.RangeFile.rawRead(ubyte[]) [0x86fa7c]
source/dub/internal/vibecompat/core/file.d:42 @safe ubyte[] dub.internal.vibecompat.core.file.RangeFile.readAll() [0x86fa32]
source/dub/packagemanager.d:360 dub.package_.Package dub.packagemanager.PackageManager.storeFetchedPackage(dub.internal.vibecompat.inet.path.NativePath, dub.internal.vibecompat.data.json.Json, dub.internal.vibecompat.inet.path.NativePath) [0x7513ff]

This should have failed in std.net.curl.download, but instead fails during unpacking. Almost as if we're missing a -f option for libcurl.

MartinNowak · 2018-01-27T18:34:15Z

Think I found the culprits (yes multiple ones as always).

18318 – std.net.curl.download silently ignores non-2xx http statuses

Also since #1104 we're only catching HTTPStatusErrors, but we also need to catch CurlErrors for things like timeouts, ssl, etc. pp.

- require arguments for test_registry - check removal of broken package

- silent http status errors (e.g. 502) should be responsible for most "corrupted" zip packages

…4.zip)

wilzbach · 2018-01-31T04:57:13Z

Ready from my side @wilzbach.

Awesome! Travis failed because you forgot to commit the 1.0.2 symlink - I added that one.

We should replace the FallbackRegistry with simply iterating over all registries at some point.

Agreed, there are lots of other things we could do as well:

cache the zip binary on the server / mirrors (at the moment all the registry does is a redirect to GH)
finally implement the git procotol (might be more stable & flexible than the zip download)
user the slightly smaller .tar.gz
...

Though of all these will require quite some effort.

wilzbach · 2018-01-31T05:05:17Z

test/fetchzip.sh

+fi
+
+echo "HTTP status errors on downloads should be retried - gitcompatibledubpackage (1.0.2)"
+retryOut=$(! timeout 1s "$DUB" fetch gitcompatibledubpackage --version=1.0.2 --skip-registry=all --registry=http://localhost:$PORT --vverbose 2>&1)


The Travis log shows an error and retryCount of 1 - despite the log clearly showing "Bad Gateway" three times:

Downloading metadata for gitcompatibledubpackage Getting from http://localhost:4934/packages/gitcompatibledubpackage.json Getting http://localhost:4934/packages/gitcompatibledubpackage.json... Fetching gitcompatibledubpackage 1.0.2... Acquiring package zip file Downloading from 'http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip' Storing http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip... Download http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip 502 Bad Gateway (1.1) Failed to download package gitcompatibledubpackage from http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip (Attempt 1 of 3) Storing http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip... Download http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip 502 Bad Gateway (1.1) Failed to download package gitcompatibledubpackage from http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip (Attempt 2 of 3) Storing http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip... Download http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip 502 Bad Gateway (1.1) Failed to download package gitcompatibledubpackage from http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip (Attempt 3 of 3) Failed to download package gitcompatibledubpackage from http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip Full exception: object.Exception@source/dub/packagesupplier.d(208): Failed to download package gitcompatibledubpackage from http://localhost:4934/packages/gitcompatibledubpackage/1.0.2.zip ---------------- source/dub/packagesupplier.d:208 void dub.packagesupplier.RegistryPackageSupplier.fetchPackage(dub.internal.vibecompat.inet.path.NativePath, immutable(char)[], dub.dependency.Dependency, bool) [0x762422] source/dub/dub.d:766 dub.package_.Package dub.dub.Dub.fetch(immutable(char)[], const(dub.dependency.Dependency), dub.project.PlacementLocation, dub.dub.FetchOptions, immutable(char)[]) [0x74bafa] source/dub/commandline.d:1235 int dub.commandline.FetchCommand.execute(dub.dub.Dub, immutable(char)[][], immutable(char)[][]) [0x70c427] source/dub/commandline.d:252 int dub.commandline.runDubCommandLine(immutable(char)[][]) [0x704e8a] source/app.d:14 _Dmain [0x6fc025] ========== -Output was ========== [ERROR] :DUB should have retried download on server error multiple times, but only tried 1 times. command failed

@safe

testregistry --- Opening file /tmp/gitcompatibledubpackage-cb607641-d990-4f5c-a426-0e158a14689e.zip rawRead must take a non-empty buffer Full exception: object.Exception@/home/travis/dlang/dmd-2.075.1/linux/bin64/../../src/phobos/std/stdio.d(902): rawRead must take a non-empty buffer ---------------- /home/travis/dlang/dmd-2.075.1/linux/bin64/../../src/phobos/std/stdio.d:902 @safe ubyte[] std.stdio.File.rawRead!(ubyte).rawRead(ubyte[]) [0xa16c4b] source/dub/internal/vibecompat/core/file.d:46 @trusted void dub.internal.vibecompat.core.file.RangeFile.rawRead(ubyte[]) [0xa01908] source/dub/internal/vibecompat/core/file.d:42 @safe ubyte[] dub.internal.vibecompat.core.file.RangeFile.readAll() [0xa01882] source/dub/packagemanager.d:360 dub.package_.Package ---

- stdx-allocator requires std.typecons.Ternary

MartinNowak · 2018-02-01T13:50:57Z

Thx for fixing this up :).

ThomasMader · 2018-02-10T09:59:06Z

I am getting the following with 1.7.2. It used to work with 1.7.1 and missed the beta release of 1.7.2.

Fetching gitcompatibledubpackage 1.0.4...
/tmp/nix-build-dubUnittests-1.7.2.drv-0/source/test/fetchzip.sh: line 21: dub: command not found
[ERROR] :21 command failed
[main(----) INF] Received signal 15. Shutting down.
[ERROR] Script failure.

wilzbach · 2018-02-10T11:56:07Z

How do you run the testsuite?

ThomasMader · 2018-02-10T12:14:41Z

It's running as part of the package building process for NixOS.
For me it seems it should not be "dub" but "$DUB" as used with the "$DUB" build command inside the same script.
dub might not be in the path.

wilzbach · 2018-02-10T12:21:48Z

dub might not be in the path.

Yes, looks like that's not the case for you.
I saw that too and currently preparing a PR that will remove the DUB environment variable from the testsuite... Sorry about the inconvenience.

wilzbach · 2018-02-10T12:25:14Z

#1368

ThomasMader · 2018-02-10T12:31:09Z

I patched it and now getting:

Trying to download gitcompatibledubpackage (1.0.4)
Package gitcompatibledubpackage not found for registry at http://localhost:5593/: Couldn't connect to server on handle CFD950
No package gitcompatibledubpackage was found matching the dependency 1.0.4
[ERROR] :17 command failed
[ERROR] Script failure.

wilzbach · 2018-02-10T12:36:56Z

Do you expose some limitations that prevent vibe.d from starting? E.g. no network access to fetch the binary?

Could you post the full log?

ThomasMader · 2018-02-10T13:38:01Z

It was my mistake, it works now.

wilzbach force-pushed the zip-exceptions branch 3 times, most recently from 82a6262 to ad7d85b Compare January 19, 2018 04:36

wilzbach commented Jan 19, 2018

View reviewed changes

wilzbach force-pushed the zip-exceptions branch 5 times, most recently from 5f4acff to 8495788 Compare January 24, 2018 17:46

wilzbach force-pushed the zip-exceptions branch 2 times, most recently from 66f13be to 6366760 Compare January 24, 2018 22:58

wilzbach and others added 7 commits January 31, 2018 03:17

Don't break out of the retry loop for ZipExceptions - fixes dlang#1336

2bd09bd

restrict zip exception handler to specific unpack statement

7cccb81

more robust testing

2e58cc1

- require arguments for test_registry - check removal of broken package

fix retry on http status error

30c872d

- silent http status errors (e.g. 502) should be responsible for most "corrupted" zip packages

unify retry counts to 3

85d065f

allow to add fallbacks to custom registry for testing purposes

8b2145f

test fallback mirror usage on server errors

659e8db

MartinNowak changed the base branch from master to stable January 31, 2018 02:19

Add symlink for 1.0.2.zip of the tested gitcompatiblepackage (to 1.0.…

8f14ccf

…4.zip)

wilzbach added the auto-merge label Jan 31, 2018

wilzbach removed the auto-merge label Jan 31, 2018

fetchzip.sh: Display $retryCount in the error log output

2f7aa5a

wilzbach commented Jan 31, 2018

View reviewed changes

wilzbach added 3 commits January 31, 2018 06:22

Use echo instead of bash here string

4ba3a65

Bump vibe.d to 0.8.3-alpha.1 for compatibility with dmd-nightly

a885e97

wilzbach added the auto-merge label Jan 31, 2018

dlang-bot removed the auto-merge label Jan 31, 2018

wilzbach force-pushed the zip-exceptions branch from 82a7e53 to a885e97 Compare January 31, 2018 05:50

wilzbach added the auto-merge label Jan 31, 2018

bump min frontend for ddox to 2.072

db084af

- stdx-allocator requires std.typecons.Ternary

dlang-bot removed the auto-merge label Jan 31, 2018

wilzbach merged commit 923285d into dlang:stable Jan 31, 2018

wilzbach deleted the zip-exceptions branch January 31, 2018 09:40

This was referenced Feb 2, 2018

Build changelog menu dynamically (replace bash with D code) dlang/dlang.org#2159

Merged

Bump DMD_VER to 2.078.2 dlang/dlang.org#2192

Merged

wilzbach mentioned this pull request Feb 10, 2018

Various improvements to the testing shell scripts #1368

Open

wilzbach mentioned this pull request Apr 5, 2018

Install the newest version of dub to avoid random network failures #1437

Merged

Uh oh!

Comments

Conversation

wilzbach commented Jan 15, 2018

Uh oh!

dlang-bot commented Jan 15, 2018

Uh oh!

wilzbach commented Jan 15, 2018

Uh oh!

wilzbach Jan 19, 2018

Choose a reason for hiding this comment

Uh oh!

MartinNowak Jan 27, 2018

Choose a reason for hiding this comment

Uh oh!

wilzbach commented Jan 24, 2018

Uh oh!

MartinNowak commented Jan 24, 2018

Uh oh!

wilzbach commented Jan 24, 2018

Uh oh!

MartinNowak commented Jan 27, 2018

Uh oh!

MartinNowak commented Jan 27, 2018

Uh oh!

wilzbach commented Jan 27, 2018

Uh oh!

MartinNowak commented Jan 27, 2018

Uh oh!

MartinNowak commented Jan 27, 2018

Uh oh!

MartinNowak commented Jan 27, 2018

Uh oh!

wilzbach commented Jan 31, 2018

Uh oh!

wilzbach Jan 31, 2018

Choose a reason for hiding this comment

Uh oh!

MartinNowak commented Feb 1, 2018

Uh oh!

ThomasMader commented Feb 10, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

wilzbach commented Feb 10, 2018

Uh oh!

ThomasMader commented Feb 10, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

wilzbach commented Feb 10, 2018

Uh oh!

wilzbach commented Feb 10, 2018

Uh oh!

ThomasMader commented Feb 10, 2018

Uh oh!

wilzbach commented Feb 10, 2018

Uh oh!

ThomasMader commented Feb 10, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

ThomasMader commented Feb 10, 2018 •

edited

Loading

ThomasMader commented Feb 10, 2018 •

edited

Loading