Bug 1374265

I tried upgrading to the latest docker-py using pip, and I got the same results.

So this doesn't look like this is fixed in newer versions of docker-py.

$ pip list | grep docker-py
You are using pip version 7.1.0, however version 8.1.2 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
docker-py (1.9.0)

$ time ./reproducer.py 
/k8s_fluentd-elasticsearch.c2b7b021_logging-fluentd-0fyea_logging_6d005e90-743d-11e6-a23f-0a3cb09b029f_132818d6
Traceback (most recent call last):
  File "./reproducer.py", line 11, in <module>
    stats = cli.stats(first_ctr['Id'], stream=False)
  File "/usr/lib/python2.7/site-packages/docker/utils/decorators.py", line 35, in wrapper
    return f(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/docker/utils/decorators.py", line 21, in wrapped
    return f(self, resource_id, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/docker/api/container.py", line 378, in stats
    return self._result(self._get(url, params={'stream': False}),
  File "/usr/lib/python2.7/site-packages/docker/utils/decorators.py", line 47, in inner
    return f(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/docker/client.py", line 140, in _get
    return self.get(url, **self._set_request_timeout(kwargs))
  File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 488, in get
    return self.request('GET', url, **kwargs)
  File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 475, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 596, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python2.7/site-packages/requests/adapters.py", line 499, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=120)

real	2m0.171s
user	0m0.083s
sys	0m0.023s

I'm still not able to reproduce b/c my local libvirt isn't working and hence I can't even access rhel 7 (https://bugzilla.redhat.com/show_bug.cgi?id=1374325 https://bugzilla.redhat.com/show_bug.cgi?id=1374486), our internal openstack won't even start a vm -,-


So in the meantime I checked sources of docker engine and this is what I came up with:

code which forms the http request:

https://github.com/projectatomic/docker/blob/rhel7-1.10.3/vendor/src/github.com/docker/engine-api/client/container_stats.go#L10

code that processes the response:

https://github.com/projectatomic/docker/blob/rhel7-1.10.3/api/client/stats.go#L40


Interesting thing is that no matter if you specify `stream` or not, server always responds with `Transfer-Encoding: chunked` which is kind of odd. If the client is interested only in a single stats instance, the server should just send the json in a single response and close. Not return a stream. You can easily observe this:

$ ncat -U /var/run/docker.sock
GET /v1.22/containers/580dc1eaae69/stats?stream=0 HTTP/1.1  # press <enter> twice and wait for response

HTTP/1.1 200 OK
Content-Type: application/json
Server: Docker/1.10.3 (linux)
Date: Fri, 09 Sep 2016 09:57:20 GMT
Transfer-Encoding: chunked

1127
{"read":"2016-09-09T09:57:20.896712812Z","precpu_stats":{"cpu_usage":{"total_usage":981229


docker client handles this weird behavior by doing only a single iteration during processing response and then just breaks out of the loop [1]. At the same time it only prints a single stats instance with --no-stream. Funny thing is that client sets "timeout" to two seconds [2] and if it doesn't get a response in that timeframe it just prints all zeros. That's what you're seeing. So instead docker client printed "hey I received no stats" it just prints those zeros. To me, docker-py does this correctly, it keeps on waiting and eventually times out.

Hence it's pretty clear that the issue is in docker engine: it doesn't respond with stats correctly in time and that's why client just keeps on waiting getting nothing.


Therefore I'm reassigning to docker component.


[1] https://github.com/projectatomic/docker/blob/rhel7-1.10.3/api/client/stats.go#L86
[2] https://github.com/projectatomic/docker/blob/rhel7-1.10.3/api/client/stats.go#L93

Is this happening with upstream docker and docker-py as well? I doubt this went unnoticed upstream, we probably need to backport a patch for this.

@amurdaca  Looks like upstream is experiencing something similar (found by ttomecek):

https://github.com/docker/docker-py/issues/1195

I have found and fixed the issue in 1.10: https://github.com/projectatomic/docker/pull/195 right now I'm working on upstream.

Upstream PR: https://github.com/docker/docker/pull/25905; my PR is just a backport.

backported to docker-1.12 and 1.10.3 with https://github.com/projectatomic/docker/pull/195

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2016-2634.html