brew: brew install download VERY slow, pauses for 10 minutes for seemingly no reason

My brew is updated. brew doctor results: Your system is ready to brew. brew config:

HOMEBREW_VERSION: 1.7.1
ORIGIN: https://github.com/Homebrew/brew
HEAD: d6a245c05110c240e680da594c2cc6038998b82e
Last commit: 8 days ago
Core tap ORIGIN: https://github.com/Homebrew/homebrew-core
Core tap HEAD: d1ae0a1e2f3294f0472410e3d3f1e4306971839e
Core tap last commit: 23 minutes ago
HOMEBREW_PREFIX: /usr/local
CPU: dodeca-core 64-bit kabylake
Homebrew Ruby: 2.3.7 => /System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/bin/ruby
Clang: 9.1 build 902
Git: 2.15.2 => /Library/Developer/CommandLineTools/usr/bin/git
Curl: 7.54.0 => /usr/bin/curl
Java: N/A
macOS: 10.13.6-x86_64
CLT: 9.4.1.0.1.1528165917
Xcode: N/A
XQuartz: N/A

So the problem I am having is that whenever I brew install any formula, the Download portion gets stuck for about 10 minutes before initiating the curl command. See below for verbose debug log with time.

Just to reiterate it is the ==> Downloading portion where it gets stuck. The verbose debug message doesn’t seem to show any errors, and I’ve tried the curl command on its own and it works fast. No idea what is happening during the ==> Downloading output.

/usr/local/Homebrew/Library/Homebrew/brew.rb (Formulary::FormulaLoader): loading /usr/local/Homebrew/Library/Taps/homebrew/homebrew-core/Formula/gmp.rb
==> Downloading https://homebrew.bintray.com/bottles/gmp-6.1.2_2.high_sierra.bottle.tar.gz
/usr/bin/curl -q --show-error --user-agent Homebrew/1.7.1 (Macintosh; Intel Mac OS X 10.13.6) curl/7.54.0 --fail --location --remote-time --continue-at - --output /Users/huanji/Library/Caches/Homebrew/gmp-6.1.2_2.high_sierra.bottle.tar.gz.incomplete https://homebrew.bintray.com/bottles/gmp-6.1.2_2.high_sierra.bottle.tar.gz
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 1005k  100 1005k    0     0  1595k      0 --:--:-- --:--:-- --:--:-- 1595k
==> Verifying gmp-6.1.2_2.high_sierra.bottle.tar.gz checksum
==> Pouring gmp-6.1.2_2.high_sierra.bottle.tar.gz
tar xf /Users/huanji/Library/Caches/Homebrew/gmp-6.1.2_2.high_sierra.bottle.tar.gz -C /var/folders/gx/9ym9tnr11bqfcp81_fb7b4m80000gp/T/d20180731-87643-aas88u
Changing dylib ID of /usr/local/Cellar/gmp/6.1.2_2/lib/libgmp.10.dylib
  from @@HOMEBREW_PREFIX@@/opt/gmp/lib/libgmp.10.dylib
    to /usr/local/opt/gmp/lib/libgmp.10.dylib
Changing dylib ID of /usr/local/Cellar/gmp/6.1.2_2/lib/libgmpxx.4.dylib
  from @@HOMEBREW_PREFIX@@/opt/gmp/lib/libgmpxx.4.dylib
    to /usr/local/opt/gmp/lib/libgmpxx.4.dylib
Changing install name in /usr/local/Cellar/gmp/6.1.2_2/lib/libgmpxx.4.dylib
  from @@HOMEBREW_CELLAR@@/gmp/6.1.2_2/lib/libgmp.10.dylib
    to /usr/local/Cellar/gmp/6.1.2_2/lib/libgmp.10.dylib
==> Finishing up
ln -s ../Cellar/gmp/6.1.2_2/include/gmp.h gmp.h
ln -s ../Cellar/gmp/6.1.2_2/include/gmpxx.h gmpxx.h
ln -s ../../Cellar/gmp/6.1.2_2/share/info/gmp.info gmp.info
info /usr/local/share/info/gmp.info
ln -s ../../Cellar/gmp/6.1.2_2/share/info/gmp.info-1 gmp.info-1
ln -s ../../Cellar/gmp/6.1.2_2/share/info/gmp.info-2 gmp.info-2
ln -s ../Cellar/gmp/6.1.2_2/lib/libgmp.10.dylib libgmp.10.dylib
ln -s ../Cellar/gmp/6.1.2_2/lib/libgmp.a libgmp.a
ln -s ../Cellar/gmp/6.1.2_2/lib/libgmp.dylib libgmp.dylib
ln -s ../Cellar/gmp/6.1.2_2/lib/libgmpxx.4.dylib libgmpxx.4.dylib
ln -s ../Cellar/gmp/6.1.2_2/lib/libgmpxx.a libgmpxx.a
ln -s ../Cellar/gmp/6.1.2_2/lib/libgmpxx.dylib libgmpxx.dylib
/usr/bin/sandbox-exec -f /private/tmp/homebrew20180731-88713-1qaf2pp.sb nice /System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/bin/ruby -W0 -I /Library/Ruby/Gems/2.3.0/gems/did_you_mean-1.0.0/lib:/Library/Ruby/Site/2.3.0:/Library/Ruby/Site/2.3.0/x86_64-darwin17:/Library/Ruby/Site/2.3.0/universal-darwin17:/Library/Ruby/Site:/System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/lib/ruby/vendor_ruby/2.3.0:/System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/lib/ruby/vendor_ruby/2.3.0/x86_64-darwin17:/System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/lib/ruby/vendor_ruby/2.3.0/universal-darwin17:/System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/lib/ruby/vendor_ruby:/System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/lib/ruby/2.3.0:/System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/lib/ruby/2.3.0/x86_64-darwin17:/System/Library/Frameworks/Ruby.framework/Versions/2.3/usr/lib/ruby/2.3.0/universal-darwin17:/usr/local/Homebrew/Library/Homebrew/cask/lib:/usr/local/Homebrew/Library/Homebrew -- /usr/local/Homebrew/Library/Homebrew/postinstall.rb /usr/local/Homebrew/Library/Taps/homebrew/homebrew-core/Formula/gmp.rb --debug --verbose
/usr/local/Homebrew/Library/Homebrew/postinstall.rb (Formulary::FromPathLoader): loading /usr/local/Homebrew/Library/Taps/homebrew/homebrew-core/Formula/gmp.rb
==> Summary
🍺  /usr/local/Cellar/gmp/6.1.2_2: 18 files, 3.1MB

real	10m3.633s
user	0m1.742s
sys	0m0.874s

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Reactions: 3
  • Comments: 21 (9 by maintainers)

Most upvoted comments

I experienced similar issues, the culprit was BitDefender Traffic Scan, which does TLS MitM in a most likely broken way, since I’ve seen it break other random HTTPS requests, like certain HEAD requests. I wasn’t able to figure out a pattern, as the software doesn’t appear to output any kind of useful logs. @mrleeio is definitely using the same software, as the certificate it uses is visible in the curl logs posted here (CN=Bitdefender CA SSL).

Disabling it (or bypassing it with a proxy) makes everything work as normal.

@MikeMcQuaid sure thing

EDIT: I forgot to mention that I tried before and after the brew reinstall -i command.

brew sh curl

brew ~$ curl https://homebrew.bintray.com/bottles/node-10.11.0.high_sierra.bottle.tar.gz -O
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
brew ~$ curl -L https://homebrew.bintray.com/bottles/node-10.11.0.high_sierra.bottle.tar.gz -O
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 12.5M  100 12.5M    0     0  9249k      0  0:00:01  0:00:01 --:--:-- 23.1M
brew ~$ ls
node-10.11.0.high_sierra.bottle.tar.gz
brew ~$ time curl -L https://homebrew.bintray.com/bottles/node-10.11.0.high_sierra.bottle.tar.gz -O
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0
100 12.5M  100 12.5M    0     0  5485k      0  0:00:02  0:00:02 --:--:-- 17.0M
curl -L  -O  0.38s user 0.07s system 19% cpu 2.357 total
brew ~$ ls
node-10.11.0.high_sierra.bottle.tar.gz
brew ~$

Within brew sh had to pass in the location flag for curl but the download itself was only 2.3 seconds. Seems like this command fails to reproduce the problem. Unless it is related to the redirect…

brew sh wget

brew ~$ time wget https://homebrew.bintray.com/bottles/node-10.11.0.high_sierra.bottle.tar.gz --no-check-certificate
--2018-09-25 07:48:06--  https://homebrew.bintray.com/bottles/node-10.11.0.high_sierra.bottle.tar.gz
Resolving homebrew.bintray.com (homebrew.bintray.com)... 108.168.243.150
Connecting to homebrew.bintray.com (homebrew.bintray.com)|108.168.243.150|:443... connected.
WARNING: cannot verify homebrew.bintray.com's certificate, issued by ‘CN=Bitdefender CA SSL,O=Endpoint,L=Bucharest,ST=Bucharest,C=RO’:
  Unable to locally verify the issuer's authority.
HTTP request sent, awaiting response... 302
Location: https://akamai.bintray.com/6f/6f1c350e623963b2fa3356d08dc0450555da66dcdcf63d824c9b4d99e40f8231?__gda__=exp=1537887606~hmac=73c4d8ef9ad2276bbed1a3e3fe142bdc660fc81424a3bc89afc202497d775b2e&response-content-disposition=attachment%3Bfilename%3D%22node-10.11.0.high_sierra.bottle.tar.gz%22&response-content-type=application%2Fgzip&requestInfo=U2FsdGVkX1-eVoI1rH0GKz5oe5eyBQVMwYqXtdQ1l6Zk8NSaQEE2-AEDA389npaL2lRvIe4vsRhMV9D0kLcqihP4Jig9Bodb0sNNPB9JwLYD4Ns-XRDyjCnzxSKyyoeBKiQeVwxoD-vE6g9IU5P65w&response-X-Checksum-Sha1=3cafa0c8024cf0493e66b3968d0729bba3cd1b23&response-X-Checksum-Sha2=6f1c350e623963b2fa3356d08dc0450555da66dcdcf63d824c9b4d99e40f8231 [following]
--2018-09-25 07:48:06--  https://akamai.bintray.com/6f/6f1c350e623963b2fa3356d08dc0450555da66dcdcf63d824c9b4d99e40f8231?__gda__=exp=1537887606~hmac=73c4d8ef9ad2276bbed1a3e3fe142bdc660fc81424a3bc89afc202497d775b2e&response-content-disposition=attachment%3Bfilename%3D%22node-10.11.0.high_sierra.bottle.tar.gz%22&response-content-type=application%2Fgzip&requestInfo=U2FsdGVkX1-eVoI1rH0GKz5oe5eyBQVMwYqXtdQ1l6Zk8NSaQEE2-AEDA389npaL2lRvIe4vsRhMV9D0kLcqihP4Jig9Bodb0sNNPB9JwLYD4Ns-XRDyjCnzxSKyyoeBKiQeVwxoD-vE6g9IU5P65w&response-X-Checksum-Sha1=3cafa0c8024cf0493e66b3968d0729bba3cd1b23&response-X-Checksum-Sha2=6f1c350e623963b2fa3356d08dc0450555da66dcdcf63d824c9b4d99e40f8231
Resolving akamai.bintray.com (akamai.bintray.com)... 23.59.158.60
Connecting to akamai.bintray.com (akamai.bintray.com)|23.59.158.60|:443... connected.
WARNING: cannot verify akamai.bintray.com's certificate, issued by ‘CN=Bitdefender CA SSL,O=Endpoint,L=Bucharest,ST=Bucharest,C=RO’:
  Unable to locally verify the issuer's authority.
HTTP request sent, awaiting response... 200 OK
Length: 13162440 (13M) [application/gzip]
Saving to: ‘node-10.11.0.high_sierra.bottle.tar.gz’

node-10.11.0.high_sierra.bottle.tar.gz                                                                                     100%[======================================================================================================================================================================================================================================================================================================================================>]  12.55M  32.8MB/s    in 0.4s

2018-09-25 07:48:07 (32.8 MB/s) - ‘node-10.11.0.high_sierra.bottle.tar.gz’ saved [13162440/13162440]

wget  --no-check-certificate  0.04s user 0.07s system 8% cpu 1.230 total
brew ~$ ls
node-10.11.0.high_sierra.bottle.tar.gz

Faster than curl, but failed to reproduce the problem again.


For todays episode of long upgrade times awscli is our contestant

~ % time brew upgrade
==> Upgrading 1 outdated package, with result:
awscli 1.16.10 -> 1.16.20
==> Upgrading awscli
==> Downloading https://homebrew.bintray.com/bottles/awscli-1.16.20.high_sierra.bottle.tar.gz
######################################################################## 100.0%
==> Pouring awscli-1.16.20.high_sierra.bottle.tar.gz
==> Caveats
The "examples" directory has been installed to:
  /usr/local/share/awscli/examples

Bash completion has been installed to:
  /usr/local/etc/bash_completion.d

zsh completions and functions have been installed to:
  /usr/local/share/zsh/site-functions
==> Summary
🍺  /usr/local/Cellar/awscli/1.16.20: 4,754 files, 43.6MB
brew upgrade  4.39s user 6.56s system 1% cpu 11:21.07 total

I will come back and fill this in when it finishes (tool 11 minutes)

@claui, the download strategies have been merged and are all using SystemCommand now, so if this is indeed the problem it should be fixed when a new tag is released.