APIError: 500 Server Error on first docker-compose up / build #1275

nathanleclaire · 2015-04-09T20:10:26Z

I noticed this when testing the most recent RC (4)

Steps to reproduce:

Clone https://github.com/nathanleclaire/hubfwd
Run docker-compose up in the repo

Expected behavior: It doesn't blow up
Actual behavior: It blows up

On the first up and the first up only, so build smells suspicious.

Creating hubfwd_app_1...
Building app...
Step 0 : FROM golang:1.4.2
 ---> 121a93c90463
Step 1 : RUN go get -u github.com/codegangsta/negroni
 ---> Running in 5e2161a172f9
 ---> 623f1c94741b
Removing intermediate container 5e2161a172f9
Step 2 : RUN go get -u github.com/gorilla/mux
 ---> Running in c74924a6c8fd
 ---> 7923dd360f79
Removing intermediate container c74924a6c8fd
Step 3 : RUN go get -u github.com/Sirupsen/logrus
 ---> Running in 93443d6cf298
 ---> 3ae5e3801312
Removing intermediate container 93443d6cf298
Step 4 : RUN mkdir -p /go/src/github.com/nathanleclaire/hubfwd
 ---> Running in 8deddcbb0f1d
 ---> 6586dfbe5b2e
Removing intermediate container 8deddcbb0f1d
Step 5 : WORKDIR /go/src/github.com/nathanleclaire/hubfwd
 ---> Running in bb42cbdf1032
 ---> 0d824f6e8519
Removing intermediate container bb42cbdf1032
Step 6 : COPY . /go/src/github.com/nathanleclaire/hubfwd
 ---> ad6983d66cf7
Removing intermediate container e16e62829fb7
Step 7 : CMD go build
 ---> Running in 550e4ab79b39
 ---> 15ebeafc0600
Removing intermediate container 550e4ab79b39
Successfully built 15ebeafc0600
Attaching to hubfwd_app_1
Exception in thread Thread-1:
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")

I'm on OSX using a VM created by docker-machine in VirtualBox (boot2docker).

The text was updated successfully, but these errors were encountered:

nathanleclaire · 2015-04-15T23:48:04Z

Bump on this - I got it with https://github.com/nathanleclaire/laraveldocker as well: (rc4)

Attaching to laraveldocker_db_1, laraveldocker_redis_1, laraveldocker_beanstalkd_1, laraveldocker_web_1
Exception in thread Thread-1:
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")

EloB · 2015-04-18T16:07:14Z

Also getting this after docker-compose up:

Versions:

docker-compose 1.2.0 (installed by sudo pip install -U https://github.com/docker/compose/archive/1.2.0.zip)
Docker version 1.6.0, build 4749651
Boot2Docker-cli version: v1.6.0 and via virtualbox
OSX Yosemite

Exception in thread Thread-1:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 810, in __bootstrap_inner
    self.run()
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 763, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/Library/Python/2.7/site-packages/compose/cli/multiplexer.py", line 41, in _enqueue_output
    for item in generator:
  File "/Library/Python/2.7/site-packages/compose/cli/log_printer.py", line 59, in _make_log_generator
    for line in line_generator:
  File "/Library/Python/2.7/site-packages/compose/cli/utils.py", line 77, in split_buffer
    for data in reader:
  File "/Library/Python/2.7/site-packages/docker/client.py", line 225, in _multiplexed_response_stream_helper
    socket = self._get_raw_response_socket(response)
  File "/Library/Python/2.7/site-packages/docker/client.py", line 167, in _get_raw_response_socket
    self._raise_for_status(response)
  File "/Library/Python/2.7/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")

Exception in thread Thread-5:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 810, in __bootstrap_inner
    self.run()
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 763, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/Library/Python/2.7/site-packages/compose/cli/multiplexer.py", line 41, in _enqueue_output
    for item in generator:
  File "/Library/Python/2.7/site-packages/compose/cli/log_printer.py", line 59, in _make_log_generator
    for line in line_generator:
  File "/Library/Python/2.7/site-packages/compose/cli/utils.py", line 77, in split_buffer
    for data in reader:
  File "/Library/Python/2.7/site-packages/docker/client.py", line 225, in _multiplexed_response_stream_helper
    socket = self._get_raw_response_socket(response)
  File "/Library/Python/2.7/site-packages/docker/client.py", line 167, in _get_raw_response_socket
    self._raise_for_status(response)
  File "/Library/Python/2.7/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")

kojiromike · 2015-04-18T18:35:51Z

👍 also experiencing this issue.

jrslv · 2015-04-20T13:58:59Z

👍

Tom-Potanski · 2015-04-20T14:44:38Z

Have you figured out the solution already?

gguimaraesbr · 2015-04-20T20:02:25Z

👍

nathanleclaire · 2015-04-20T20:27:05Z

For anyone reading, it seems that if I do docker-compose build manually and then do a docker-compose up everything works fine. That should hopefully serve as a workaround until this gets addressed.

aanand · 2015-04-21T11:30:28Z

I can reproduce. @nathanleclaire's workaround (docker-compose build first) does indeed fix it for me.

Looking at the docker inspect output of a container in both the working and failing case, I can't find anything obvious that's wrong. Very strange.

mamigot · 2015-04-21T17:23:19Z

Me too, and running docker-compose build and then docker-compose up like @nathanleclaire said fixes it

ghost · 2015-04-23T02:13:53Z

Yay, this workaround worked for me too.

thenayr · 2015-04-23T23:24:18Z

Experiencing the same issue here, same versions

rdsubhas · 2015-04-24T08:09:45Z

+1, same issue/version, thanks for the workaround!

rvion · 2015-04-27T15:42:47Z

+1, same problem for me

LK4D4 · 2015-04-28T15:47:46Z

Somehow your up supports http://golang.org/pkg/net/http/#CloseNotifier and build not :)

LK4D4 · 2015-04-28T16:08:03Z

I think problem is in keep-alive, so in one connection you build and attach. To fix this you need to create new connection, not sure how can we fix it on docker side.

LK4D4 · 2015-04-28T16:14:10Z

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

noahsw · 2015-04-29T00:37:10Z

+1

aanand · 2015-04-29T12:53:53Z

@LK4D4: nice find. I wonder if there's a way to force docker-py/requests to create a new connection for attaching. @shin-?

dnephin · 2015-04-29T14:02:07Z

It looks like docker.Client extends http://docs.python-requests.org/en/latest/api/#request-sessions, so I think we could call client.close() and that would force it to re-establish a new connection.

aanand · 2015-04-29T16:57:10Z

@dnephin Nice. Fix in #1374.

…ompose-issue-1275 Updated README for docker/compose#1275

Tjorriemorrie · 2015-08-04T09:56:09Z

In which docker version is this fix? I'm still experiencing it on Docker version 1.3.1, build 4e9bbfa

isuftin · 2015-08-31T13:37:02Z

Still getting this in:

docker-compose 1.2.0

Docker version 1.8.1, build d12ea79

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")

dnephin · 2015-08-31T13:57:47Z

The fix is in docker-compose 1.3.0

nathanleclaire added the kind/bug label Apr 9, 2015

delfick mentioned this issue Apr 28, 2015

Hijack is incompatible with use of CloseNotifier moby/moby#12845

Closed

noahsw added a commit to winsleague/winsleague that referenced this issue Apr 29, 2015

Updated README for docker/compose#1275

daf91b8

noahsw mentioned this issue Apr 29, 2015

docker-compose build fails winsleague/winsleague#14

Closed

aanand mentioned this issue Apr 29, 2015

Close connection after building or pulling #1374

Merged

aanand self-assigned this Apr 29, 2015

aanand added the in progress label Apr 29, 2015

dnephin closed this as completed in #1374 Apr 29, 2015

dnephin removed the in progress label Apr 29, 2015

charleskrueger added a commit to winsleague/winsleague that referenced this issue May 1, 2015

Merge pull request #15 from league-wins-pool/feature/workaround-for-c…

b3339e6

…ompose-issue-1275 Updated README for docker/compose#1275

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

APIError: 500 Server Error on first docker-compose up / build #1275

APIError: 500 Server Error on first docker-compose up / build #1275

nathanleclaire commented Apr 9, 2015

nathanleclaire commented Apr 15, 2015

EloB commented Apr 18, 2015

kojiromike commented Apr 18, 2015

jrslv commented Apr 20, 2015

Tom-Potanski commented Apr 20, 2015

gguimaraesbr commented Apr 20, 2015

nathanleclaire commented Apr 20, 2015

aanand commented Apr 21, 2015

mamigot commented Apr 21, 2015

ghost commented Apr 23, 2015

thenayr commented Apr 23, 2015

rdsubhas commented Apr 24, 2015

rvion commented Apr 27, 2015

LK4D4 commented Apr 28, 2015

LK4D4 commented Apr 28, 2015

LK4D4 commented Apr 28, 2015

noahsw commented Apr 29, 2015

aanand commented Apr 29, 2015

dnephin commented Apr 29, 2015

aanand commented Apr 29, 2015

Tjorriemorrie commented Aug 4, 2015

isuftin commented Aug 31, 2015

dnephin commented Aug 31, 2015

APIError: 500 Server Error on first docker-compose up / build #1275

APIError: 500 Server Error on first docker-compose up / build #1275

Comments

nathanleclaire commented Apr 9, 2015

nathanleclaire commented Apr 15, 2015

EloB commented Apr 18, 2015

kojiromike commented Apr 18, 2015

jrslv commented Apr 20, 2015

Tom-Potanski commented Apr 20, 2015

gguimaraesbr commented Apr 20, 2015

nathanleclaire commented Apr 20, 2015

aanand commented Apr 21, 2015

mamigot commented Apr 21, 2015

ghost commented Apr 23, 2015

thenayr commented Apr 23, 2015

rdsubhas commented Apr 24, 2015

rvion commented Apr 27, 2015

LK4D4 commented Apr 28, 2015

LK4D4 commented Apr 28, 2015

LK4D4 commented Apr 28, 2015

noahsw commented Apr 29, 2015

aanand commented Apr 29, 2015

dnephin commented Apr 29, 2015

aanand commented Apr 29, 2015

Tjorriemorrie commented Aug 4, 2015

isuftin commented Aug 31, 2015

dnephin commented Aug 31, 2015