request canceled (Client.Timeout exceeded while awaiting headers)

[Michael Nelson]

We're getting reports of sporadic timeouts when using snap refresh.

popey says: """
error: cannot refresh []: Post https://search.apps.ubuntu.com/api/v1/snaps/metadata: net/http: request canceled (Client.Timeout exceeded while awaiting headers)

I get it a _lot_
"""

Manik sees: """
2016-11-07T20:44:16Z ERROR Get https://assertions.ubuntu.com/v1/assertions/snap-revision/8KlxmAnVLkQ-ysEZUbHOUPR55bVmb7G6bYhfmK0kduEHGe337epeP5_lxwDe6cEH: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
"""

I was able to reproduce it once, before what seems like an unrelated issue: """
ubuntu@dev-xenial:~/golang/src/github.com/snapcore/snapd$ snap refresh
error: cannot refresh []: cannot refresh snap-declaration for "blr-says": Get https://assertions.ubuntu.com/v1/assertions/snap-declaration/16/hqfOKHESqlxD49VsxjZkkWtQHrSTmC5L?max-format=1: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)

ubuntu@dev-xenial:~/golang/src/github.com/snapcore/snapd$ snap refresh
error: cannot communicate with server: Get http://localhost/v2/changes/202: dial unix /run/snapd.socket: connect: connection refused
"""

***NOTE*** If you are able to reproduce this, please install tcdump and run:

$ sudo tcpdump host search.apps.ubuntu.com and port 443 -i any -w store.pcap

in one terminal, while you reproduce in another terminal. Once reproduced, CTRL-C to stop tcpdump and then attach the store.pcap as a comment below.

[Michael Nelson (michael.nelson)]

We don't have any evidence of issues with the service(s) themselves, according to graphs, yet. Trying to see if there are related networking issues at the time, without any success yet.

[Michael Nelson (michael.nelson)]

00:09 < wgrant> noodles: There was a slight dip in the PS4½ firewall graph around then, but it's difficult to establish significance.

[Michael Nelson (michael.nelson)]

This was reported again today on the snapcraft mailing list. Frontend server logs show only successful results:

http://paste.ubuntu.com/23602216/ (the IPs were from Mexico, China, China, then the last 3 were my IP from canonistack).

Not sure yet whether the request is not reaching Apache, or Apache has its hands tied at the time serving large updates from SCA for packages with many revisions (though nothing stands out on our graphs that I can see at the time).

[Greg Lutostanski (lutostag)]

I've seen this error myself, not in mainland China, but Austin. Happens when I first connect to the store over spotty-wifi (and with a few retries it goes away).

Any info I can gather client-side?

[Greg Lutostanski (lutostag)]

Adding snappy bug, so people can find it from that search too. (That is where I first looked)

[Greg Lutostanski (lutostag)]

(Sorry, changed rather than added new project), Apologies.

[Oliver Grawert (ogra)]

i just hit this as well today and it turned out that my canonical VPN connection did not let me through for whatever reason ... restarting the VPN competely resolved it.

[dinamic (dinamic6661)]

i get this error all the time LOL, i have this silly cheap tenda rounter, and from time to time the wifi just dies X-( and i have to restart the router to make the wifi work again. i have dynamic ip.
so after i restart the router i see this message

snap refresh ubuntu-app-platform --edge
error: cannot refresh "ubuntu-app-platform": cannot get refresh information for snap "ubuntu-app-platform": Post https://search.apps.ubuntu.com/api/v1/snaps/metadata: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)

to fix this i just click on the network indicator with my mouse and disconect and reconnect my wired connection and then boom! no more errors.

i can reproduce this every time

[Bret Barker (noise)]

dinamic - since you are able to reproduce this, I wonder if you could provide more detail. First off, what version of snapd are you running (`snap version`)? Second, after you reset your wifi and before issuing the the `snap refresh` could you do a: `sudo netstat -pant | grep snap`

Thanks in advance.

[Hassan (hsn-zamani)]

I have the same issue here. Here are the details:

```
$ snap version
snap 2.24.1+17.04
snapd 2.24.1+17.04
series 16
ubuntu 17.04
kernel 4.10.0-20-generic

$ sudo netstat -pant | grep snap
# returns 1

$ sudo snap refresh
error: cannot refresh []: Post https://search.apps.ubuntu.com/api/v1/snaps/metadata: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
```

[Samuel Cozannet (samuel-cozannet)]

Same error on 2 nodes in the same LAN on

snap 2.25
Ubuntu 16.04
kernel 4.4.0-83-generic

One of the nodes is a VM, the other a physical machine, managed via MAAS / Juju. This breaks the install of the kubernetes-worker, but others nodes on the network are fine.

Very weird.

[Samuel Cozannet (samuel-cozannet)]

I was able to fix the issue with the following procedure:

1. Edit /etc/systemd/system/snapd.service.d/snap_layer_proxy.conf
2. Put the "no_proxy" Environment on the last line of the file instead of the first
  * on "working nodes", it was on the last line
  * on "failing nodes" it was on the first line
3. sudo systemctl daemon-reload
4. sudo systemctl restart snapd.service

and there you go. To be noted that my env has a proxy for http/https and apt.

[Alvaro Uria (aluria)]

I've run into the same issue.

* Node is in Asia
* snap info grafana takes "real 0m50.056s".
* snap_layer_proxy.conf looks like (no no_proxy env var):
"""
~# cat /etc/systemd/system/snapd.service.d/snap_layer_proxy.conf
# Managed by Juju
[Service]
Environment=https_proxy=http://192.168.x.x:8000/
Environment=http_proxy=http://192.168.x.x:8000/
"""

* snap versions
"""
~# snap version
snap 2.45
snapd 2.45
series 16
ubuntu 16.04
kernel 4.15.0-91-generic
"""

* snap refresh grafana returns:
"""
error: cannot refresh "grafana": cannot refresh snap-declaration for "core18": Get
       https://api.snapcraft.io/api/v1/snaps/assertions/snap-declaration/16/<a-long-id>?max-format=4:
       net/http: request canceled while waiting for connection (Client.Timeout exceeded while
       awaiting headers)
"""