Hijack is incompatible with use of CloseNotifier

[delfick]

Hi,

I upgraded my docker to 1.6 today (I believe it was on 1.5, but I'm not 100% sure).

I now have a problem where my docker client gives me docker.errors.APIError: 500 Server Error: Internal Server Error ("http: Hijack is incompatible with use of CloseNotifier") when I try to post to /containers/<container>/attach (my client uses dockerpty and docker-py)

It would appear that compose has a similar problem (docker/compose#1275).

If I run an image with the docker cli it does work (for example, docker run -it ubuntu:14.04 /bin/bash)

I'm not entirely sure how to debug this issue.

Thanks

Stephen.

[LK4D4]

Hmm, this is pretty weird, compose running into this on build and that's the place where we use CloseNotifier.

[LK4D4]

ping @pwaller
Seems like attach just crashing build if client supports CloseNotifier.

[pwaller]

I don't understand how this is happening. There's only one call to CloseNotifier, and it's in postBuild. How are we ending up calling Hijack thereafter on the same w?

https://github.com/docker/docker/search?utf8=%E2%9C%93&q=CloseNotifier&type=Code

[LK4D4]

@pwaller Dunno :/ Maybe connection is used for two requests?

[pwaller]

@LK4D4 could it be a go bug then? That is really weird. It would be useful to see the exact sequence of events and connections involved. I'm not likely to spend a lot of time delving into this, though it has piqued my curiosity a bit.

[LK4D4]

@pwaller I wonder what about keep-alive, so you first calling Build, then Attach and hijack in attach failing.

[LK4D4]

@delfick Do you build something before attach?

[pwaller]

@LK4D4 I guess it could be keep-alive, but I would expect the effects of the CloseNotifier to have finished by the time the connection is ready to be reused for the attach. (hence my suggestion that it could be a bug).

[LK4D4]

@pwaller https://go-review.googlesource.com/#/c/3821/

[pwaller]

@LK4D4 nice find, good to see it's being fixed in general.

However, I still don't understand the sequence of events that is causing the problem as reported here. Do we think someone fires off a build, and at some point later tries to attach, and they're still using the same socket to communicate to the daemon? I'm surprised that this triggers the issue. I guess the workaround is to tell clients to kill their keep-alive after a build or before an attach :(

[LK4D4]

@pwaller Yeah, seems like many users of api can trigger this with Keep-Alive. I already suggested them to reopen connections in docker/compose#1275

[delfick]

I agree, removing the build step makes it work (my docker client reads yaml that embeds the dockerfile and so it always rebuilds the image before running)

I'll put in code that recreates the connection for now. Good to see there's an actual fix in the pipeline.

[mko-x]

Just as info: +1

Stacktrace may help a little:

Traceback (most recent call last):
File "/compose/build/docker-compose/out00-PYZ.pyz/threading", line 810, in __bootstrap_inner
File "/compose/build/docker-compose/out00-PYZ.pyz/threading", line 763, in run
File "/compose/build/docker-compose/out00-PYZ.pyz/compose.cli.multiplexer", line 41, in _enqueue_output
File "/compose/build/docker-compose/out00-PYZ.pyz/compose.cli.log_printer", line 59, in _make_log_generator
File "/compose/build/docker-compose/out00-PYZ.pyz/compose.cli.utils", line 77, in split_buffer
File "/compose/build/docker-compose/out00-PYZ.pyz/docker.client", line 199, in _multiplexed_response_stream_helper
File "/compose/build/docker-compose/out00-PYZ.pyz/docker.client", line 143, in _get_raw_response_socket
File "/compose/build/docker-compose/out00-PYZ.pyz/docker.client", line 95, in _raise_for_status
APIError: 500 Server Error: Internal Server Error ("http: Hijack is incompatible with use of CloseNotifier")

[ogavrisevs]

+1

Exception in thread Thread-1:
Traceback (most recent call last):
File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/threading.py", line 532, in __bootstrap_inner
self.run()
File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/threading.py", line 484, in run
self.__target(_self.__args, *_self.__kwargs)
File "/Library/Python/2.6/site-packages/compose/cli/multiplexer.py", line 41, in _enqueue_output
for item in generator:
File "/Library/Python/2.6/site-packages/compose/cli/log_printer.py", line 59, in _make_log_generator
for line in line_generator:
File "/Library/Python/2.6/site-packages/compose/cli/utils.py", line 77, in split_buffer
for data in reader:
File "/Library/Python/2.6/site-packages/docker/client.py", line 225, in _multiplexed_response_stream_helper
socket = self._get_raw_response_socket(response)
File "/Library/Python/2.6/site-packages/docker/client.py", line 167, in _get_raw_response_socket
self._raise_for_status(response)
File "/Library/Python/2.6/site-packages/docker/client.py", line 119, in _raise_for_status
raise errors.APIError(e, response, explanation=explanation)
APIError: 500 Server Error: Internal Server Error ("http: Hijack is incompatible with use of CloseNotifier")

[koliyo]

+1

[Glideh]

+1

(docker 1.6.2)

[LK4D4]

ping @aanand
Can you confirm that it is fixed on compose side?

[aanand]

Yeah, we fixed it in docker/compose#1374.

[catuss-a]

+1

[Bekt]

@aanand I have the latest docker and compose but I still receive the error. Any suggestions?

[mbentley]

Still with the RC? That fixed it here for me.

[hoIIer]

+1

[hoIIer]

@aanand how do I upgrade to that version on osx? (new to docker)

[aanand]

@erichonkanen Follow the instructions here: https://github.com/docker/compose/releases/tag/1.3.0rc1

However, there's a known bug with that RC - if you get an SSL error, hold tight for the fix (docker/compose#1474).

[catuss-a]

docker-compose 1.2.0
Docker version 1.6.2, build 7c8fca2

Do I need to upgrade ? Cause I got this error yesterday many times when building my app up with dc up. However it runs fine when I rerun it just after.

[aanand]

Yep - 1.2.0 has the bug, and running build followed by up is a workaround.

[catuss-a]

@aanand Ok thanks dude! I've noticed as well when I remove all my stuff related to docker (hard way: docker rm -f docker ps -aq&& docker rmi -fdocker images -q``) and then build up my app with docker-compose up, then apparently it can't fetch the required deleted images (of mysql for example: from mysql:latest) . I have to docker-compose pull in order to download those.

[aanand]

@catuss-a Sorry to hear - please open an issue on https://github.com/docker/compose for that.

[moxiegirl]

+1

[funkytaco]

👍

I uninstalled the docker-compose binary installed by Kitematic and installed docker-compose via homebrew and this error went away.

[lascarayf]

+1

[bastianwegge]

+1

[thaJeztah]

@aanand @LK4D4 if I understand correctly, this is a docker-compose, and fixed in docker-compose 1.3?

if so, can this be closed?

[thaJeztah]

s/docker-compose/docker-compose issue/ ^^

[funkytaco]

Yeah, in my case that's the only change I made to resolve the error (upgrade docker-compose).

[delfick]

The fix is more of a workaround.

Where we just instantiate a new docker client to avoid reusing the same connection.

[funkytaco]

I think @pwaller was right in saying it was a Go bug. See https://go-review.googlesource.com/#/c/3821/

Docker-compose worked around it in docker/compose#1374

[pwaller]

@thaJeztah I personally think this can be closed. I don't think there is anything that can be done docker-side, only "client" side (so, in compose, docker-py, etc etc). There is a workaround available (turn off HTTP connection reuse (aka Keep-Alive)), and it will be fixed when go fixes golang/go#9763 which has been marked 1.6Early. I'll try and create some noise for that when their next release cycle starts.

[thaJeztah]

Thanks @pwaller, I'll close this issue for now, but others feel free to comment here if you think there's something that can be done in Docker itself.

[aeikenberry]

I'm getting this error after upgrading today.

docker info

Containers: 8
 Running: 2
 Paused: 0
 Stopped: 6
Images: 282
Server Version: 1.12.0-rc3
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 320
 Dirperm1 Supported: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: host null overlay bridge
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Security Options: seccomp
Kernel Version: 4.4.14-moby
Operating System: Alpine Linux v3.4
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 1.954 GiB
Name: moby
ID: JRAU:RVZS:OEOQ:JMBF:PRR6:7TPD:UG5U:TRR6:4T2W:AGWF:5TFV:SLD2
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 29
 Goroutines: 47
 System Time: 2016-07-05T20:24:15.611271815Z
 EventsListeners: 1
No Proxy: *.local, 169.254/16
Username: aeikenberry
Registry: https://index.docker.io/v1/
Experimental: true
Insecure Registries:
 127.0.0.0/8

For example:
docker-compose run django python manage.py migrate

http: Hijack is incompatible with use of CloseNotifier in same ServeHTTP call
http: Hijack is incompatible with use of CloseNotifier in same ServeHTTP call

[cpuguy83]

@aeikenberry Thanks for the report, this is a bug with docker4mac and is pretty much being tracked in docker/compose#3685