Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

nix no longer loads channel or cache #41312

Closed
NeQuissimus opened this issue May 31, 2018 · 10 comments
Closed

nix no longer loads channel or cache #41312

NeQuissimus opened this issue May 31, 2018 · 10 comments
Labels
0.kind: regression Something that worked before working no longer 1.severity: blocker This is preventing another PR or issue from being completed 1.severity: security Issues which raise a security issue, or PRs that fix one 6.topic: nixos Issues or PRs affecting NixOS modules, or package usability issues specific to NixOS 6.topic: user experience

Comments

@NeQuissimus
Copy link
Member

NeQuissimus commented May 31, 2018

Issue description

nix on master seems to no longer be able to download channel information

Steps to reproduce

λ nix-channel --add https://nixos.org/channels/nixos-unstable unstable
λ nix-channel --update
warning: unable to download 'https://nixos.org/channels/nixos-unstable': Timeout was reached (28); retrying in 349 ms
warning: unable to download 'https://nixos.org/channels/nixos-unstable': Timeout was reached (28); retrying in 515 ms
warning: unable to download 'https://nixos.org/channels/nixos-unstable': Timeout was reached (28); retrying in 1065 ms
warning: unable to download 'https://nixos.org/channels/nixos-unstable': Timeout was reached (28); retrying in 2793 ms
error: unable to download 'https://nixos.org/channels/nixos-unstable': Timeout was reached (28)

Note that it has nothing to do with my Internet connection:

λ curl -L https://nixos.org/channels/nixos-unstable
<html><head><title>nixos-unstable release nixos-18.09pre140920.5b468ea6b1d</title></head><body><h1>nixos-unstable release nixos-18.09pre140920.5b468ea6b1d</h1><p>Released on 2018-05-27 22:16:32 from <a href='https://github.com/NixOS/nixpkgs-channels/commits/5b468ea6b1d8d243847a05bdf5603e8abdfd7b4e'>Git commit <tt>5b468ea6b1d8d243847a05bdf5603e8abdfd7b4e</tt></a> via <a href='https://hydra.nixos.org/eval/1459044'>Hydra evaluation 1459044</a>.</p><table>
[...]

This generation of mine from two days ago works just fine:

λ ls -la /nix/var/nix/profiles/system-194-link 
lrwxrwxrwx 88 root 30 May 10:54 /nix/var/nix/profiles/system-194-link -> /nix/store/shcl3hnyn27275h5d4xqwhjq6php5cxc-nixos-system-nixus-desktop-18.09.git.bbfd8e4

Technical details

Can't run nix-shell -p nix-info --run "nix-info -m" successfully :)

λ nix-shell -p nix-info --run "nix-info -m"
warning: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28); retrying in 302 ms
warning: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28); retrying in 604 ms
warning: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28); retrying in 1242 ms
warning: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28); retrying in 2356 ms
warning: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28); retrying in 4133 ms
warning: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28); retrying in 9319 ms
warning: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28); retrying in 18044 ms
error: unable to download 'https://cache.nixos.org/fjazq1b9xkgjamx9g9wxsv0mcix1k2gw.narinfo': Timeout was reached (28)

I just did a nixos-rebuild boot --upgrade -I ${HOME}/dev/nixpkgs from a git checkout on master @ f0ac006

@NeQuissimus NeQuissimus added 6.topic: nixos Issues or PRs affecting NixOS modules, or package usability issues specific to NixOS 1.severity: blocker This is preventing another PR or issue from being completed 6.topic: user experience 0.kind: regression Something that worked before working no longer labels May 31, 2018
@dtzWill
Copy link
Member

dtzWill commented May 31, 2018

That's clearly no good!

Not sure what'd cause that, I assume you are still experiencing the problem? ("hopefully"?)

If so, can you try running with however-many "-v"s are needed to get libcurl debug logging (I admit I usually just do "-vvvvvvvvvv")? Perhaps also using the curl tool directly as well?

And nix-channel/etc should be 2.0.4, but can you double-check the versions (store paths?).

And just to check--when those timeouts are reached do they seem to match "wall time" roughly? First few might be hard to judge but the longer ones should be possible to determine if they're firing much too quickly or not. I've been seeing issues with the bump to curl 7.60 re:nix and timeouts so just want to check. :).

@NeQuissimus
Copy link
Member Author

This is the output over and over:

λ nix-channel -vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv --update
locking path '/home/nequi/.cache/nix/tarballs/1gnlb51dzi5671rrmdhjcgrmlm2s0q039mv7ib0hcqgvd6j4yxqv-file'
download thread waiting for 10000 ms
lock acquired on '/home/nequi/.cache/nix/tarballs/1gnlb51dzi5671rrmdhjcgrmlm2s0q039mv7ib0hcqgvd6j4yxqv-file.lock'
downloading 'https://nixos.org/channels/nixos-unstable'...
starting download of https://nixos.org/channels/nixos-unstable
curl: Couldn't find host nixos.org in the .netrc file; using defaults
download thread waiting for 10000 ms
download thread waiting for 10000 ms
download thread waiting for 10000 ms
download thread waiting for 10000 ms
curl: Resolving timed out after 10010 milliseconds
curl: stopped the pause stream!
curl: Closing connection 0
finished download of 'https://nixos.org/channels/nixos-unstable'; curl status = 28, HTTP status = 0, body = 0 bytes
warning: unable to download 'https://nixos.org/channels/nixos-unstable': Timeout was reached (28); retrying in 322 ms
download thread waiting for 10000 ms
download thread waiting for 321 ms
download thread waiting for 0 ms
download thread waiting for 0 ms
download thread waiting for 0 ms
download thread waiting for 0 ms
download thread waiting for 0 ms
download thread waiting for 0 ms
download thread waiting for 0 ms
download thread waiting for 0 ms

Plain curl is fine:

λ curl -Lvvvvvvvvvvvvvv https://nixos.org/channels/nixos-unstable
*   Trying 54.217.220.47...
* TCP_NODELAY set
* Connected to nixos.org (54.217.220.47) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server accepted to use http/1.1
* Server certificate:
*  subject: CN=nixos.org
*  start date: May 13 23:19:18 2018 GMT
*  expire date: Aug 11 23:19:18 2018 GMT
*  subjectAltName: host "nixos.org" matched cert's "nixos.org"
*  issuer: C=US; O=Let's Encrypt; CN=Let's Encrypt Authority X3
*  SSL certificate verify ok.
> GET /channels/nixos-unstable HTTP/1.1
> Host: nixos.org
> User-Agent: curl/7.60.0
> Accept: */*
> 
< HTTP/1.1 302 Found
< Date: Fri, 01 Jun 2018 12:29:56 GMT
< Server: Apache/2.4.33 (Unix) OpenSSL/1.0.2n
< Strict-Transport-Security: max-age=15552000
< Location: https://d3g5gsiof5omrk.cloudfront.net/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d
< Content-Length: 269
< Content-Type: text/html; charset=iso-8859-1
< 
* Ignoring the response-body
* Connection #0 to host nixos.org left intact
* Issue another request to this URL: 'https://d3g5gsiof5omrk.cloudfront.net/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d'
*   Trying 52.84.139.114...
* TCP_NODELAY set
* Connected to d3g5gsiof5omrk.cloudfront.net (52.84.139.114) port 443 (#1)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: C=US; ST=Washington; L=Seattle; O=Amazon.com Inc.; CN=*.cloudfront.net
*  start date: Nov 22 00:00:00 2017 GMT
*  expire date: Nov 21 12:00:00 2018 GMT
*  subjectAltName: host "d3g5gsiof5omrk.cloudfront.net" matched cert's "*.cloudfront.net"
*  issuer: C=US; O=DigiCert Inc; CN=DigiCert Global CA G2
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x1a0416b0)
> GET /nixos/unstable/nixos-18.09pre140920.5b468ea6b1d HTTP/2
> Host: d3g5gsiof5omrk.cloudfront.net
> User-Agent: curl/7.60.0
> Accept: */*
> 
* Connection state changed (MAX_CONCURRENT_STREAMS == 128)!
< HTTP/2 200 
< content-type: text/html
< content-length: 2878
< date: Mon, 28 May 2018 00:27:38 GMT
< last-modified: Sun, 27 May 2018 22:20:16 GMT
< etag: "97b16702aaa0b61351cb8b34214950b9"
< accept-ranges: bytes
< server: AmazonS3
< age: 78092
< x-cache: Hit from cloudfront
< via: 1.1 dd6c0f8f395c63719afb6847f93b2248.cloudfront.net (CloudFront)
< x-amz-cf-id: 3SRm2wwNadfHgY03A7CxTAfFaPMMg2YQKgS73MIWc2xDryVhKEgWwg==
< 
<html><head><title>nixos-unstable release nixos-18.09pre140920.5b468ea6b1d</title></head><body><h1>nixos-unstable release nixos-18.09pre140920.5b468ea6b1d</h1><p>Released on 2018-05-27 22:16:32 from <a href='https://github.com/NixOS/nixpkgs-channels/commits/5b468ea6b1d8d243847a05bdf5603e8abdfd7b4e'>Git commit <tt>5b468ea6b1d8d243847a05bdf5603e8abdfd7b4e</tt></a> via <a href='https://hydra.nixos.org/eval/1459044'>Hydra evaluation 1459044</a>.</p><table><thead><tr><th>File name</th><th>Size</th><th>SHA-256 hash</th></tr></thead><tbody><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/binary-cache-url'>binary-cache-url</a></td><td align='right'>23</td><td><tt>eb8d2a51d85521c07092ed8126df19bb6f9d7c16a5275395a0e110868a4ac6c0</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/git-revision'>git-revision</a></td><td align='right'>40</td><td><tt>7e52c5c502e192732a2cf16e21ca0c8c834560c3b1a7e81a2b31e2bdedbc6f83</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/nixexprs.tar.xz'>nixexprs.tar.xz</a></td><td align='right'>11206924</td><td><tt>48daa609dce296dcd9944e6579d8c01fa786508f4829e8e341eef2a2b6b0e50e</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/nixos-18.09pre140920.5b468ea6b1d-x86_64-linux.ova'>nixos-18.09pre140920.5b468ea6b1d-x86_64-linux.ova</a></td><td align='right'>1145083392</td><td><tt>785f1bbd4d3aa190cf7937acf39f6404674c6f0622dfb923be50f7ae73e48d64</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/nixos-graphical-18.09pre140920.5b468ea6b1d-x86_64-linux.iso'>nixos-graphical-18.09pre140920.5b468ea6b1d-x86_64-linux.iso</a></td><td align='right'>1209008128</td><td><tt>e68f72fc218657e76dd95ef125b9389b05827be3ba4c3f99f8914f08ece66554</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/nixos-minimal-18.09pre140920.5b468ea6b1d-i686-linux.iso'>nixos-minimal-18.09pre140920.5b468ea6b1d-i686-linux.iso</a></td><td align='right'>506462208</td><td><tt>00154c8695fbc* Connection #1 to host d3g5gsiof5omrk.cloudfront.net left intact
eb8a8ae020a187702657a35e2dc848aca44a5aca4922a2dc07f</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/nixos-minimal-18.09pre140920.5b468ea6b1d-x86_64-linux.iso'>nixos-minimal-18.09pre140920.5b468ea6b1d-x86_64-linux.iso</a></td><td align='right'>502267904</td><td><tt>aa6179f3fff61d3c282d7519f3b3e6b652a749e5ff7138af8bc152f89b413101</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/src-url'>src-url</a></td><td align='right'>36</td><td><tt>fa422a9fb11ed8fd0c8185945d5dbad1ddde8bbc717445f69909ce13b4f68b09</tt></td></tr><tr><td><a href='/nixos/unstable/nixos-18.09pre140920.5b468ea6b1d/store-paths.xz'>store-paths.xz</a></td><td align='right'>733532</td><td><tt>40ca1ed9b57045b999b597dd98e2d388d97aff0f5c0c7f19427bae5b8193043b</tt></td></tr></tbody></table></body></html>% 

My nix is indeed 2.0.4:

λ readlink -e $(type -p nix-channel)
/nix/store/yxrpzcmhss2ja038fzb49db901gh82qr-nix-2.0.4/bin/nix-channel

The timeouts seem to be 10 seconds and watch wall time.

@NeQuissimus
Copy link
Member Author

Update: I have updated another machine to the same versions and there the failures are flaky.

NeQuissimus added a commit to NeQuissimus/nixpkgs that referenced this issue Jun 4, 2018
This reverts commit 44101ee.

All nix tools appear to be flaky and run into timeouts with curl 7.60.0
See NixOS#41312 for more details
@orivej
Copy link
Contributor

orivej commented Jun 4, 2018

I can not reproduce the failure, but nix-channel --update indeed does not behave normally. Instead of

curl: Couldn't find host nixos.org in the .netrc file; using defaults
download thread waiting for 10000 ms
download thread waiting for 10000 ms
download thread waiting for 10000 ms
download thread waiting for 10000 ms
curl: Resolving timed out after 10010 milliseconds

from the log above I get

curl: Couldn't find host nixos.org in the .netrc file; using defaults
download thread waiting for 10000 ms
download thread waiting for 10000 ms
download thread waiting for 10000 ms
download thread waiting for 10000 ms
# <-- here it sleeps for 10 seconds
curl:   Trying 54.217.220.47...
# <-- now it continues normally

So I can debug this 10 second sleep.

@dtzWill
Copy link
Member

dtzWill commented Jun 8, 2018

Maybe related: NixOS/nix#1536

Particularly noteworthy is that the version complained about (7.55) is where threaded resolver was first enabled by default I think. Err well it's 7.55.1 not 7.55.0, hmm.

Maybe it's something else entirely 😁

@dtzWill
Copy link
Member

dtzWill commented Sep 18, 2018

I haven't tested yet but upstream commit (see linked issue) looks somewhat promising regarding this:

curl/curl@ec5d099

Don't get too excited, but will report what I find when I get a chance to give it a go :). Builders are all busy with other things hehe.

@vcunat
Copy link
Member

vcunat commented Jan 16, 2019

Any ideas about this? Our nix keeps using curl affected by multiple security problems! #53569 and linked.

@vcunat vcunat added the 1.severity: security Issues which raise a security issue, or PRs that fix one label Jan 16, 2019
@LnL7
Copy link
Member

LnL7 commented Jan 16, 2019

@dtzWill I think I just figured out the darwin fork bug because of your comment NixOS/nix#2523 (comment)

I'm not sure, but if this also works around the problems for linux we could do this by default instead of using an old version.

@NeQuissimus
Copy link
Member Author

I just built nix with the regular curl and the above nix-channel commands work just fine. I suppose the bug could have just been fixed in nix or curl in the meantime... I, at least, don't seem to be able to reproduce the issue anymore.

vcunat added a commit that referenced this issue Jan 19, 2019
This reverts commit 5574df3.
I also can't reproduce the problem anymore; discussion: #41312.
Fixes #53569, fixes #53948.  (Vulnerabilities in old curl.)
vcunat added a commit to vcunat/nixpkgs that referenced this issue Jan 19, 2019
This reverts commit 5574df3.
I also can't reproduce the problem anymore; discussion: NixOS#41312.
Fixes NixOS#53569, fixes NixOS#53948.  (Vulnerabilities in old curl.)

(cherry picked from commit 51ac3db)
vcunat added a commit that referenced this issue Jan 26, 2019
This reverts commit 5574df3.
I also can't reproduce the problem anymore; discussion: #41312.
Fixes #53569, fixes #53948.  (Vulnerabilities in old curl.)

(cherry picked from commit 51ac3db)
I've noticed no complaints about this change on unstable/master.
@vcunat
Copy link
Member

vcunat commented Feb 19, 2019

Let's close until something like this reappears.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
0.kind: regression Something that worked before working no longer 1.severity: blocker This is preventing another PR or issue from being completed 1.severity: security Issues which raise a security issue, or PRs that fix one 6.topic: nixos Issues or PRs affecting NixOS modules, or package usability issues specific to NixOS 6.topic: user experience
Projects
None yet
Development

No branches or pull requests

5 participants