Pub: flutter packages get repeatedly tries to fetch packages if a packages in pubspec does not exist

Created on 31 Oct 2019 · 19Comments · Source: dart-lang/pub

Hi,

just stumbled upon this here when trying to add a new package to the project and made a typo. Instead of just getting the message that the package doesn't exist I got this here

Running "flutter pub get" in compass_test...                           -Batchvorgang abbrechen (J/N)? j
PS C:\Entwicklung\projects\Aaronia\trunk\Sources\RTSAMobileDev\tests\compass_test> flutter packages get -v
[  +19 ms] executing: [C:\Entwicklung\flutter\] git -c log.showSignature=false log -n 1 --pretty=format:%H
[  +40 ms] Exit code 0 from: git -c log.showSignature=false log -n 1 --pretty=format:%H
[        ] 8e0799a657051bf540d98b8aecf9cfa1325f3f71
[        ] executing: [C:\Entwicklung\flutter\] git describe --match v*.*.* --first-parent --long --tags
[  +48 ms] Exit code 0 from: git describe --match v*.*.* --first-parent --long --tags
[        ] v1.10.14-351-g8e0799a65
[   +5 ms] executing: [C:\Entwicklung\flutter\] git rev-parse --abbrev-ref --symbolic @{u}
[  +26 ms] Exit code 0 from: git rev-parse --abbrev-ref --symbolic @{u}
[        ] origin/master
[        ] executing: [C:\Entwicklung\flutter\] git ls-remote --get-url origin
[  +26 ms] Exit code 0 from: git ls-remote --get-url origin
[   +3 ms] https://github.com/flutter/flutter
[  +50 ms] executing: [C:\Entwicklung\flutter\] git rev-parse --abbrev-ref HEAD
[  +24 ms] Exit code 0 from: git rev-parse --abbrev-ref HEAD
[        ] master
[  +31 ms] Artifact Instance of 'AndroidMavenArtifacts' is not required, skipping update.
[        ] Artifact Instance of 'AndroidGenSnapshotArtifacts' is not required, skipping update.  
[        ] Artifact Instance of 'AndroidInternalBuildArtifacts' is not required, skipping update.
[        ] Artifact Instance of 'IOSEngineArtifacts' is not required, skipping update.
[        ] Artifact Instance of 'FlutterWebSdk' is not required, skipping update.
[   +3 ms] Artifact Instance of 'WindowsEngineArtifacts' is not required, skipping update.       
[        ] Artifact Instance of 'MacOSEngineArtifacts' is not required, skipping update.
[        ] Artifact Instance of 'LinuxEngineArtifacts' is not required, skipping update.
[        ] Artifact Instance of 'LinuxFuchsiaSDKArtifacts' is not required, skipping update.     
[   +7 ms] Artifact Instance of 'MacOSFuchsiaSDKArtifacts' is not required, skipping update.
[        ] Artifact Instance of 'FlutterRunnerSDKArtifacts' is not required, skipping update.
[  +62 ms] Running "flutter pub get" in compass_test...
[   +4 ms] executing: [C:\Entwicklung\projects\Aaronia\trunk\Sources\RTSAMobileDev\tests\compass_test\] C:\Entwicklung\flutter\bin\cache\dart-sdk\bin\pub.bat --verbose get --no-precompile
[ +112 ms] FINE: Pub 2.6.0-dev.8.2.flutter-d50c158d42
[   +1 ms] IO  : Spawning "cmd /c ver" in C:\Entwicklung\projects\Aaronia\trunk\Sources\RTSAMobileDev\tests\compass_test\.
[   +2 ms] IO  : Finished ver. Exit code 0.
[  +21 ms]     | stdout:
[        ]     | | 
[        ]     | | Microsoft Windows [Version 10.0.18362.418]
[        ]     | Nothing output on stderr.
[  +31 ms] MSG : Resolving dependencies...
[   +6 ms] SLVR: fact: compass_test is 1.0.0+1
[   +2 ms] SLVR: derived: compass_test
[  +18 ms] SLVR: fact: compass_test depends on flutter any from sdk
[   +9 ms] SLVR: fact: compass_test depends on wflutter_compass any
[        ] SLVR: fact: compass_test depends on rxdart any
[        ] SLVR: fact: compass_test depends on cupertino_icons ^0.1.2
[        ] SLVR: fact: compass_test depends on flutter_test any from sdk
[        ] SLVR:   selecting compass_test
[        ] SLVR:   derived: flutter_test any from sdk
[        ] SLVR:   derived: cupertino_icons ^0.1.2
[        ] SLVR:   derived: rxdart any
[        ] SLVR:   derived: wflutter_compass any
[        ] SLVR:   derived: flutter any from sdk
[        ] IO  : Get versions from https://pub.dartlang.org/api/packages/wflutter_compass.
[   +5 ms] IO  : HTTP GET https://pub.dartlang.org/api/packages/wflutter_compass
[  +15 ms]     | Accept: application/vnd.pub.v2+json
[   +1 ms]     | X-Pub-OS: windows
[  +14 ms]     | X-Pub-Command: get
[        ]     | X-Pub-Session-ID: 9593CBEA-0177-4ACA-B4E1-77A1C1444BC8
[  +22 ms]     | X-Pub-Environment: flutter_cli:get
[        ]     | X-Pub-Reason: direct
[        ]     | user-agent: Dart pub 2.6.0-dev.8.2.flutter-d50c158d42
[ +246 ms] IO  : HTTP response 404 Not Found for GET https://pub.dartlang.org/api/packages/wflutter_compass
[        ]     | took 0:00:00.303111
[        ]     | date: Thu, 31 Oct 2019 10:11:02 GMT
[  +14 ms]     | content-length: 9
[   +1 ms]     | strict-transport-security: max-age=31536000; preload
[        ]     | via: 1.1 google
[        ]     | content-type: text/plain
[        ]     | x-frame-options: SAMEORIGIN
[        ]     | x-xss-protection: 1; mode=block
[        ]     | x-content-type-options: nosniff
[        ]     | server: dart:io with Shelf
[        ] SLVR:   fact: wflutter_compass doesn't exist (could not find package wflutter_compass at https://pub.dartlang.org)
[        ] SLVR:   conflict: wflutter_compass doesn't exist (could not find package wflutter_compass at https://pub.dartlang.org)
[        ] SLVR:   ! wflutter_compass any is satisfied by wflutter_compass any
[        ] SLVR:   ! which is caused by "compass_test depends on wflutter_compass any"
[        ] SLVR:   ! thus: version solving failed
[        ] SLVR: Version solving took 0:00:00.360259 seconds.
[        ]     | Tried 1 solutions.
[        ] FINE: Resolving dependencies finished (0.364s).
[        ] ERR : Because compass_test depends on wflutter_compass any which doesn't exist (could not find package wflutter_compass at https://pub.dartlang.org), version solving failed.
[        ] FINE: Exception type: SolveFailure
[  +25 ms] FINE: package:pub/src/solver/version_solver.dart 308:5   VersionSolver._resolveConflict
[        ]     | package:pub/src/solver/version_solver.dart 131:27  VersionSolver._propagate
[        ]     | package:pub/src/solver/version_solver.dart 96:9    VersionSolver.solve
[        ]     | ===== asynchronous gap ===========================
[        ]     | dart:async                                         Future.catchError
[        ]     | package:pub/src/utils.dart 109:52                  captureErrors.<fn>
[        ]     | package:stack_trace                                Chain.capture
[        ]     | package:pub/src/utils.dart 122:11                  captureErrors
[        ]     | package:pub/src/command_runner.dart 171:13         PubCommandRunner.runCommand
[        ]     | dart:async                                         _completeOnAsyncReturn
[        ]     | package:pub/src/command_runner.dart                PubCommandRunner._validatePlatform
[        ]     | dart:async                                         _completeOnAsyncReturn
[   +1 ms]     | package:pub/src/io.dart                            runProcess.<fn>
[   +2 ms] pub get failed (server unavailable) -- attempting retry 1 in 1 second...
[+1002 ms] executing: [C:\Entwicklung\projects\Aaronia\trunk\Sources\RTSAMobileDev\tests\compass_test\] C:\Entwicklung\flutter\bin\cache\dart-sdk\bin\pub.bat --verbose get --no-precompile
[  +85 ms] FINE: Pub 2.6.0-dev.8.2.flutter-d50c158d42
[        ] IO  : Spawning "cmd /c ver" in C:\Entwicklung\projects\Aaronia\trunk\Sources\RTSAMobileDev\tests\compass_test\.
[   +7 ms] IO  : Finished ver. Exit code 0.
[   +7 ms]     | stdout:
[   +1 ms]     | | 
[        ]     | | Microsoft Windows [Version 10.0.18362.418]
[        ]     | Nothing output on stderr.
[  +45 ms] MSG : Resolving dependencies...

and this repeats forever.

I'm on

Flutter 1.10.15-pre.351 • channel master • https://github.com/flutter/flutter
Framework • revision 8e0799a657 (4 hours ago) • 2019-10-30 23:33:38 -0700
Engine • revision b16eab6aff
Tools • Dart 2.6.0 (build 2.6.0-dev.8.2 d50c158d42)

Source

escamoteur

All 19 comments

I think the cause here is that Pub uses the same exit code (69) for "server unavailable" and "this package does not exist", and Flutter assumes it's always the first.

I think the best fix would be for pub to have separate error codes for these, then Flutter can just retry for the first - however I don't know if changing the error code would be breaking.

(This issue might be better raised at https://github.com/flutter/flutter and https://github.com/dart-lang/pub - I thought it was a timeout issue when I first pasted the link to this repo :-))

DanTup on 31 Oct 2019

👎1

Traced this to https://github.com/flutter/flutter/pull/11882 any chance @Hixie has insights on why Flutter retries pub get. Afaik pub uses package:http_retry internally, so I'm not sure what we're trying to fix by retrying the operation.

Side note, while exit code 69 is specified as:

/// A service is unavailable.
const UNAVAILABLE = 69;

in lib/src/exit_codes.dart.

This file references BSDs sysexits manpage which specifies:

     EX_UNAVAILABLE (69)   A service is unavailable.  This can occur if a sup-
               port program or file does not exist.  This can also
               be used as a catchall message when something you
               wanted to do does not work, but you do not know
               why.

Thus, it it's probably fine to use it as a permanent error for the case where a package does not exist on the remote server, or even a catch-all as is the case in command_runner.dart.

If we did want to provide a separate error code for temporary failures I would think EX_TEMPFAIL is more appropriate. But given that we have retries in pub already, I'm not sure it is appropriate to do nested retries. Once pub get has done retries with exponential-backoff it's probably fair to consider the internet connection to be missing or blocked by firewall, etc.

jonasfj on 31 Oct 2019

Note. I was able to reproduce this on Flutter master channel.

jonasfj on 31 Oct 2019

Pub has temporary failures very frequently (many times a day in our CI alone), so we try to wrap every invocation of pub with infinite retry and truncated exponential backoff. (We actually have a bunch more places where we call pub get without using the flutter tool that fail frequently that we're considering adding retries to as well, but we haven't gotten to them yet.) Code 69 seems to be used a lot for temporary failures. I believe we also see 66, I forget if we've added 66 to the list of codes to check for.

It would be ideal for the pub tool to itself do all this retry and become extremely reliable, then we could remove all this logic from the flutter tool. We definitely would prefer to defer to the pub tool for this kind of thing. Let me know if there's anything we can do to help.

Hixie on 31 Oct 2019

Pub has temporary failures very frequently (many times a day in our CI alone), so we try to wrap every invocation of pub with infinite retry and truncated exponential backoff.

@Hixie, Thanks for the insight.. who should we talk to get some of those logs. We're are very keen to improve reliability on both pub client and server.

Maybe the retry logic doesn't handle all network failures, or we have too few retries.

jonasfj on 1 Nov 2019

Just run pub get in a loop, it'll fail sooner or later...

Hixie on 3 Nov 2019

👍1

Running pub get with my WiFi disabled seems to fail immediately with 69 and no retry:

dantup-macbookpro:Dart Sample dantup$ pub get
Resolving dependencies... 
Could not resolve URL "https://pub.dartlang.org".

dantup-macbookpro:Dart Sample dantup$ echo $?
69

So presumably if my network wobbled legitimately, this would happen. Should it be retrying?

DanTup on 4 Nov 2019

Hixie on 6 Nov 2019

Just run pub get in a loop, it'll fail sooner or later...

I ran pub get in a loop with the following program:

import 'dart:io';
import 'dart:async';

main() async {
  while (true) {
    try {
      Directory('test/cache').deleteSync(recursive: true);
      File('test/pubspec.lock').deleteSync();
      File('test/.poackages').deleteSync();
    } on FileSystemException {
      // Ignore.
    }
    final version = ((await Process.run('pub', ['--version'])).stdout as String).trim();
    final stopwatch = Stopwatch()..start();
    final r = await Process.run('pub', ['get', '--no-precompile'],
        environment: {'PUB_CACHE': 'cache'}, workingDirectory: 'test');
    stopwatch.stop();
    final s = File('logs').openWrite(mode: FileMode.append);
    if (r.exitCode == 0) {
      s.writeln(
          '**** Succeded pub get ${DateTime.now().toIso8601String()} $version ${stopwatch.elapsed}');
    } else {
      s.writeln(
          '**** Failed pub get ${DateTime.now().toIso8601String()} $version Error code ${r.exitCode} ${stopwatch.elapsed}');
      s.write('stdOut:\n${r.stdout}');
      s.write('stdErr:\n${r.stderr}');
    }
    s.close();
    await Future.delayed(Duration(seconds: 10));
  }
}

test/pubspec.yaml contains:

name: test_app
dev_dependencies:
  test:

It now had: 12715 runs in a row with no failures.

sigurdm on 7 Nov 2019

Can you reproduce https://github.com/dart-lang/pub/issues/2242#issuecomment-549304772? That fails with no retries for me (it's contrived, but I don't think it's impossible that legit network failures could fail in the same way, and it seems like a path that isn't retrying).

DanTup on 7 Nov 2019

Can you reproduce #2242 (comment)?

I only have a wired network on my workstation, I tried to disable that, and I got a few retries and a message:

**** Failed pub get 2019-11-07T13:47:41.892178 Pub 2.6.0-dev.8.1 Error code 69 0:01:03.580813
stdOut:
Resolving dependencies...
It looks like pub.dartlang.org is having some trouble.
Pub will wait for a while before trying to connect again.
stdErr:
Got socket error trying to find package test at https://pub.dartlang.org.

sigurdm on 7 Nov 2019

What if you force it to fail on DNS by giving a bad hostname like this?

$ PUB_HOSTED_URL=https://pub.notdartlang.org/ pub get
Resolving dependencies... 
Could not resolve URL "https://pub.notdartlang.org".

$

That fails in the same way for me without having to kill my network.

DanTup on 7 Nov 2019

👍1

It now had: 12715 runs in a row with no failures.

Is that hitting the network? You probably need a pubspec.yaml that involves interacting with the server.
You may also need to make sure your network is a less reliable connection to Google's data centers than whatever you are using. :-) Try running it on Cirrus or Travis or some such maybe.

Hixie on 9 Nov 2019

I think travis runs in GCP, from looking at a few of their IPs.

But it's certainly possible that DNS lookup failures are hard to produce this way. I can't find any docs about GCP, but in EC2 dns lookup failures are to be retried. And I suspect we don't attempt this, as we have some undocumented os error code we do not retry.

We tried to do some archaeology on why we don't retry these specific error codes, but all we could find was something about migrating from curl.
https://github.com/dart-lang/pub/blob/d15067931a6b671a1c9dcc98b5923347676269cf/lib/src/http.dart#L75-L87

I suspect one of these could be DNS lookup related. In any cases, retrying any I/O related error from the OS is not a risk. The worst that can happen is that it takes longer time before the end-user is informed that: (A) you don't have internet; (B) the server you specified doesn't exist.

jonasfj on 11 Nov 2019

By coincidence, I just had this in Dart-Code's integration tests on Travis. It's the same failure as my contrived example above, but real (a DNS failure, and not retried):

$ dart-sdk/bin/pub global activate --no-executables stagehand
Resolving dependencies...
Could not resolve URL "https://pub.dartlang.org".
The command "dart-sdk/bin/pub global activate --no-executables stagehand" failed and exited with 69 during .
Your build has been stopped.

I don't know the underlying cause (whether it's Travis side of the DNS servers for pub), but I do suspect it had retried a few times with a delay it probably would've subsequently worked.

DanTup on 11 Nov 2019

failed and exited with 69 during .

Also, I think there's something missing from that error. The full job log is at https://travis-ci.org/Dart-Code/Dart-Code/jobs/610241513.

DanTup on 11 Nov 2019

Could not resolve URL "https://pub.dartlang.org".

This is exactly the error codes I propose we don't handle in #2254. I probably still have to make it more graceful, but DNS lookups should be retried. It seems a bit unintuitive because the OS does DNS resolution for us, but I certainly recall having this issue in EC2 a few years ago.

jonasfj on 11 Nov 2019

Hi, is there a way to limit the number of retries? And maybe the time between retries, too?

I don't want our build server to try the operation an unlimited number of times.
"Resource not reachable -> Build failed" is perfectly fine, independent of the reason.

The last mistyped URL for example caused it to retry 232 times before I killed it.