Unable to run s2i after MacOS update (10.12.2)

[aelmadho]

Running with docker-machine and xhyve driver, I am no longer able to run s2i:

s2i build https://github.com/openshift/django-ex centos/python-35-centos7 hello-pytho2

[aelmadho]

Ahmeds-MBP-2:~ aelmadhoun$ s2i build https://github.com/openshift/django-ex centos/python-35-centos7 hello-pytho2 --loglevel=3 | tee log2.txt
I1229 14:12:56.704957 1924 main.go:68] Running S2I version "v1.1.3"
I1229 14:12:56.731695 1924 docker.go:511] Image "centos/python-35-centos7:latest" not available locally, pulling ...
unexpected fault address 0x1c5e5f8b9d5
fatal error: fault
[signal 0xb code=0x1 addr=0x1c5e5f8b9d5 pc=0x14165]

goroutine 1 [running]:
runtime.throw(0x5ee028, 0x5)
/usr/lib/golang/src/runtime/panic.go:547 +0x90 fp=0xc820518760 sp=0xc820518748
runtime.sigpanic()
/usr/lib/golang/src/runtime/sigpanic_unix.go:27 +0x2ba fp=0xc8205187b0 sp=0xc820518760
runtime.ifacethash(0x1c5e5f8b9cd, 0xc820013988, 0x0)
/usr/lib/golang/src/runtime/iface.go:406 +0x15 fp=0xc8205187b8 sp=0xc8205187b0
github.com/openshift/source-to-image/vendor/golang.org/x/net/context.parentCancelCtx(0x1c5e5f8b9cd, 0xc820013988, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/golang.org/x/net/context/context.go:258 +0x43 fp=0xc8205187e8 sp=0xc8205187b8
github.com/openshift/source-to-image/vendor/golang.org/x/net/context.removeChild(0x1c5e5f8b9cd, 0xc820013988, 0xa0b080, 0xc820204000)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/golang.org/x/net/context/context.go:273 +0x2f fp=0xc820518828 sp=0xc8205187e8
github.com/openshift/source-to-image/vendor/golang.org/x/net/context.(*timerCtx).cancel(0xc820204000, 0xc820518801, 0xa02028, 0xc8200139c0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/golang.org/x/net/context/context.go:398 +0x9f fp=0xc820518868 sp=0xc820518828
github.com/openshift/source-to-image/vendor/golang.org/x/net/context.WithDeadline.func3()
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/golang.org/x/net/context/context.go:373 +0x3d fp=0xc820518890 sp=0xc820518868
github.com/openshift/source-to-image/pkg/docker.stiDocker.InspectImage(0xa0aee0, 0xc82030b8f0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/docker/docker.go:149 +0x187 fp=0xc820518b80 sp=0xc820518890
github.com/openshift/source-to-image/pkg/docker.(*stiDocker).GetOnBuild(0xc820306600, 0xc8202e9440, 0x1f, 0x0, 0x0, 0x0, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/docker/docker.go:480 +0xb2 fp=0xc820518c88 sp=0xc820518b80
github.com/openshift/source-to-image/pkg/docker.(*stiDocker).IsImageOnBuild(0xc820306600, 0x7fff5fbff911, 0x18, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/docker/docker.go:472 +0x35 fp=0xc820518cd0 sp=0xc820518c88
github.com/openshift/source-to-image/pkg/docker.PullImage(0x7fff5fbff911, 0x18, 0xa0af70, 0xc820306600, 0x601e70, 0xe, 0xa0af00, 0xc820306600, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/docker/util.go:226 +0x2c0 fp=0xc820518d80 sp=0xc820518cd0
github.com/openshift/source-to-image/pkg/docker.pullAndCheck(0x7fff5fbff911, 0x18, 0xa0af70, 0xc820306600, 0x601e70, 0xe, 0xc820518f70, 0x0, 0x0, 0x0, ...)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/docker/util.go:298 +0x81 fp=0xc820518df0 sp=0xc820518d80
github.com/openshift/source-to-image/pkg/docker.GetBuilderImage(0xc820518f70, 0xc8201c31d8, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/docker/util.go:321 +0x10f fp=0xc820518e80 sp=0xc820518df0
github.com/openshift/source-to-image/pkg/api/describe.describeBuilderImage(0xc820216380, 0x7fff5fbff911, 0x18, 0xa0add8, 0xc8202d4200)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/api/describe/describer.go:102 +0x11b fp=0xc8205192a8 sp=0xc820518e80
github.com/openshift/source-to-image/pkg/api/describe.Config.func1(0xa0add8, 0xc8202d4200, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/api/describe/describer.go:25 +0x2dd fp=0xc820519620 sp=0xc8205192a8
github.com/openshift/source-to-image/pkg/api/describe.tabbedString(0xc820519758, 0x0, 0x0, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/api/describe/describer.go:165 +0x144 fp=0xc8205196d8 sp=0xc820519620
github.com/openshift/source-to-image/pkg/api/describe.Config(0xc820216380, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/api/describe/describer.go:86 +0x6a fp=0xc820519788 sp=0xc8205196d8
main.newCmdBuild.func1(0xc8202cc5a0, 0xc8202d2680, 0x3, 0x4)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/cmd/s2i/main.go:147 +0x1117 fp=0xc820519bb0 sp=0xc820519788
github.com/openshift/source-to-image/vendor/github.com/spf13/cobra.(*Command).execute(0xc8202cc5a0, 0xc8202d2500, 0x4, 0x4, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/github.com/spf13/cobra/command.go:547 +0x85a fp=0xc820519cc8 sp=0xc820519bb0
github.com/openshift/source-to-image/vendor/github.com/spf13/cobra.(*Command).Execute(0xc8202cc1e0, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/github.com/spf13/cobra/command.go:630 +0x46a fp=0xc820519dd0 sp=0xc820519cc8
main.main()
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/cmd/s2i/main.go:415 +0x99a fp=0xc820519f10 sp=0xc820519dd0
runtime.main()
/usr/lib/golang/src/runtime/proc.go:188 +0x2b0 fp=0xc820519f60 sp=0xc820519f10
runtime.goexit()
/usr/lib/golang/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc820519f68 sp=0xc820519f60

goroutine 5 [chan receive]:
github.com/openshift/source-to-image/vendor/github.com/golang/glog.(*loggingT).flushDaemon(0x8db8c0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/github.com/golang/glog/glog.go:882 +0x67
created by github.com/openshift/source-to-image/vendor/github.com/golang/glog.init.1
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/github.com/golang/glog/glog.go:410 +0x297

goroutine 6 [syscall]:
os/signal.signal_recv(0x0)
/usr/lib/golang/src/runtime/sigqueue.go:116 +0x132
os/signal.loop()
/usr/lib/golang/src/os/signal/signal_unix.go:22 +0x18
created by os/signal.init.1
/usr/lib/golang/src/os/signal/signal_unix.go:28 +0x37

goroutine 18 [select]:
github.com/openshift/source-to-image/vendor/github.com/docker/engine-api/client/transport/cancellable.Do.func3(0xa0b040, 0xc820013988, 0xc8204e0070, 0xc820310000)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/github.com/docker/engine-api/client/transport/cancellable/cancellable.go:79 +0xef
created by github.com/openshift/source-to-image/vendor/github.com/docker/engine-api/client/transport/cancellable.Do
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/github.com/docker/engine-api/client/transport/cancellable/cancellable.go:85 +0x336

goroutine 10 [select]:
net/http.(*persistConn).readLoop(0xc82011b1e0)
/usr/lib/golang/src/net/http/transport.go:1185 +0xd52
created by net/http.(*Transport).dialConn
/usr/lib/golang/src/net/http/transport.go:860 +0x10a6

goroutine 11 [select]:
net/http.(*persistConn).writeLoop(0xc82011b1e0)
/usr/lib/golang/src/net/http/transport.go:1280 +0x472
created by net/http.(*Transport).dialConn
/usr/lib/golang/src/net/http/transport.go:861 +0x10cb

goroutine 34 [IO wait]:
net.runtime_pollWait(0xa0c118, 0x72, 0xc8202d8c00)
/usr/lib/golang/src/runtime/netpoll.go:160 +0x60
net.(*pollDesc).Wait(0xc82030baa0, 0x72, 0x0, 0x0)
/usr/lib/golang/src/net/fd_poll_runtime.go:73 +0x3a
net.(*pollDesc).WaitRead(0xc82030baa0, 0x0, 0x0)
/usr/lib/golang/src/net/fd_poll_runtime.go:78 +0x36
net.(*netFD).Read(0xc82030ba40, 0xc8202d8c00, 0x400, 0x400, 0x0, 0xa02050, 0xc820012048)
/usr/lib/golang/src/net/fd_unix.go:250 +0x23a
net.(*conn).Read(0xc82002e400, 0xc8202d8c00, 0x400, 0x400, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/net.go:172 +0xe4
crypto/tls.(*block).readFromUntil(0xc820314e40, 0xa0c228, 0xc82002e400, 0x5, 0x0, 0x0)
/usr/lib/golang/src/crypto/tls/conn.go:460 +0xcc
crypto/tls.(*Conn).readRecord(0xc8202e6c00, 0x6f4c17, 0x0, 0x0)
/usr/lib/golang/src/crypto/tls/conn.go:562 +0x2d1
crypto/tls.(*Conn).Read(0xc8202e6c00, 0xc82031f000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/golang/src/crypto/tls/conn.go:939 +0x167
net/http.noteEOFReader.Read(0xa10700, 0xc8202e6c00, 0xc82011b248, 0xc82031f000, 0x1000, 0x1000, 0x3f00000000162c25, 0x0, 0x0)
/usr/lib/golang/src/net/http/transport.go:1690 +0x67
net/http.(*noteEOFReader).Read(0xc82044b440, 0xc82031f000, 0x1000, 0x1000, 0x198, 0x0, 0x0)
:284 +0xd0
bufio.(*Reader).fill(0xc8204470e0)
/usr/lib/golang/src/bufio/bufio.go:97 +0x1e9
bufio.(*Reader).ReadSlice(0xc8204470e0, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/lib/golang/src/bufio/bufio.go:328 +0x21a
net/http/internal.readChunkLine(0xc8204470e0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/http/internal/chunked.go:110 +0x53
net/http/internal.(*chunkedReader).beginChunk(0xc820448060)
/usr/lib/golang/src/net/http/internal/chunked.go:47 +0x39
net/http/internal.(*chunkedReader).Read(0xc820448060, 0xc8204de602, 0x5fe, 0x5fe, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/http/internal/chunked.go:77 +0xb7
net/http.(*body).readLocked(0xc820316040, 0xc8204de602, 0x5fe, 0x5fe, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/http/transfer.go:651 +0xa1
net/http.(*body).Read(0xc820316040, 0xc8204de602, 0x5fe, 0x5fe, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/http/transfer.go:643 +0x110
net/http.(*bodyEOFSignal).Read(0xc820316080, 0xc8204de602, 0x5fe, 0x5fe, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/http/transport.go:1616 +0x26a
github.com/openshift/source-to-image/vendor/github.com/docker/engine-api/client/transport/cancellable.(*notifyingReader).Read(0xc820448090, 0xc8204de602, 0x5fe, 0x5fe, 0xbf, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/vendor/github.com/docker/engine-api/client/transport/cancellable/cancellable.go:100 +0x7a
encoding/json.(*Decoder).refill(0xc82005e000, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/stream.go:152 +0x287
encoding/json.(*Decoder).readValue(0xc82005e000, 0x1, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/stream.go:128 +0x413
encoding/json.(*Decoder).Decode(0xc82005e000, 0x50b280, 0xc820212b00, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/stream.go:57 +0x159
github.com/openshift/source-to-image/pkg/docker.(*stiDocker).PullImage.func1(0xc820484300, 0x0, 0x0)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/docker/docker.go:569 +0x3a3
github.com/openshift/source-to-image/pkg/util.TimeoutAfter.func1(0xc8204803f0, 0xc820484300, 0xc82048a060)
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/util/timeout.go:34 +0x2a
created by github.com/openshift/source-to-image/pkg/util.TimeoutAfter
/go/src/github.com/openshift/source-to-image/_output/local/go/src/github.com/openshift/source-to-image/pkg/util/timeout.go:38 +0xa3

goroutine 16 [IO wait]:
net.runtime_pollWait(0xa0c058, 0x72, 0xc8201d2400)
/usr/lib/golang/src/runtime/netpoll.go:160 +0x60
net.(*pollDesc).Wait(0xc820052530, 0x72, 0x0, 0x0)
/usr/lib/golang/src/net/fd_poll_runtime.go:73 +0x3a
net.(*pollDesc).WaitRead(0xc820052530, 0x0, 0x0)
/usr/lib/golang/src/net/fd_poll_runtime.go:78 +0x36
net.(*netFD).Read(0xc8200524d0, 0xc8201d2400, 0x400, 0x400, 0x0, 0xa02050, 0xc820012048)
/usr/lib/golang/src/net/fd_unix.go:250 +0x23a
net.(*conn).Read(0xc820496010, 0xc8201d2400, 0x400, 0x400, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/net.go:172 +0xe4
crypto/tls.(*block).readFromUntil(0xc82000fb90, 0xa0c228, 0xc820496010, 0x5, 0x0, 0x0)
/usr/lib/golang/src/crypto/tls/conn.go:460 +0xcc
crypto/tls.(*Conn).readRecord(0xc8202e6300, 0x6f4c17, 0x0, 0x0)
/usr/lib/golang/src/crypto/tls/conn.go:562 +0x2d1
crypto/tls.(*Conn).Read(0xc8202e6300, 0xc8202c6000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/golang/src/crypto/tls/conn.go:939 +0x167
net/http.noteEOFReader.Read(0xa10700, 0xc8202e6300, 0xc82049e2d8, 0xc8202c6000, 0x1000, 0x1000, 0xa9e3, 0x0, 0x0)
/usr/lib/golang/src/net/http/transport.go:1690 +0x67
net/http.(*noteEOFReader).Read(0xc82044a7a0, 0xc8202c6000, 0x1000, 0x1000, 0xc8204f5d0d, 0x0, 0x0)
:284 +0xd0
bufio.(*Reader).fill(0xc8204465a0)
/usr/lib/golang/src/bufio/bufio.go:97 +0x1e9
bufio.(*Reader).Peek(0xc8204465a0, 0x1, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/lib/golang/src/bufio/bufio.go:132 +0xcc
net/http.(*persistConn).readLoop(0xc82049e270)
/usr/lib/golang/src/net/http/transport.go:1076 +0x177
created by net/http.(*Transport).dialConn
/usr/lib/golang/src/net/http/transport.go:860 +0x10a6

goroutine 49 [select]:
net/http.(*persistConn).writeLoop(0xc82049e270)
/usr/lib/golang/src/net/http/transport.go:1280 +0x472
created by net/http.(*Transport).dialConn
/usr/lib/golang/src/net/http/transport.go:861 +0x10cb
Ahmeds-MBP-2:~ aelmadhoun$ s2i build https://github.com/openshift/django-ex centos/python-35-centos7 hello-pytho2 --loglevel=3 | tee log2.txt
I1229 14:13:23.581523 1927 main.go:68] Running S2I version "v1.1.3"

[bparees]

@csrwng can you see if you can recreate this either w/ the latest release, or w/ the code in master? we may just need to do a new release.

[csrwng]

I am running MacOS Sierra (10.12.2)
I am not able to reproduce with:

• The code in master + Docker for Mac (stable 1.12.5 (14777))
• The code in master + docker-machine (version 0.8.2, build e18a919) + docker-machine-driver-xhyve (v 0.3.1) + docker (version 1.12.5)

My guess is that this is an issue with either docker, docker-machine, or docker-machine-driver-xhyve. Please try updating them to the latest version. You'll need to re-create your docker-machine so it picks up the latest docker image.

[aelmadho]

I have re-installed MacOS Sierra in case my install went bad, and I have re-installed all the same versions of docker, docker-machine and docker-machine-driver-xhyve (homebrew), I also removed the $HOME/.docker and re-created a brand new VM (Virtualbox & Xhyve), both run into an exception.

I am attaching a copy of the trace logs in case anyone may have an insight into what is going on. I also believe the issue is in downloading the image only, as I was able to run the same docker image (on same docker-machine/xhyve VM/same docker image) and it works.

After I manually downloaded the image, I was able to run s2i given the image was previously downloaded. Do you think there is any sort of library update that I am missing, any pointer would really be helpful as I think there is something in the way s2i downloads the image that is causing the segmentation fault.
s2i_download_image_failure.txt

[csrwng]

@aelmadho Ahh I see ... the issue is the execution context during the pull timing out and causing the go panic. We should not have a timeout for a pull. This is not a Mac specific issue. It has to do with the time it takes to perform the docker operation.

Let me take a look and see if this has been fixed recently.

[csrwng]

It's still an issue, I'll submit a fix.

[aelmadho]

Thank you @csrwng, we all appreciate your support.

[csrwng]

@jim-minter just fyi ... my theory was that the pull was taking longer than the timeout and that somehow the code was proceeding without the pull having completed. However, earlier today I had a chance to test that theory and was not able to reproduce. Bottom line is that I still don't know why the panic is happening. It could be completely unrelated to the pull.

[jim-minter]

The latest s2i release we published (1.1.3) is compiled using Go 1.6, which does not support MacOS Sierra. This is resolved in Go 1.7.1. golang/go#16570

@aelmadho are you able to compile master for yourself using latest 1.7 and see if you still have the issue?

@bparees we will surely need to spin a new s2i release, but I suggest hanging fire on it until we know if master works for the reporter.

[jim-minter]

(edited previous comment: Go 1.6 does not support MacOS Sierra, period.)

[jim-minter]

@aelmadho if you're able to test (and don't want to compile it yourself) I've put a build at https://gist.github.com/jim-minter/3247c647bbcf2eef11320e4961a739c5/raw/65f2fa2742e0a8fa93d44fda1395015b4119d8fc/source-to-image-v1.1.3-83-g74ab5f1-74ab5f1-darwin-amd64.tar.gz - feedback is welcome.

[jim-minter]

@bparees please will you spin a new s2i release using 1.7.x?

[bparees]

@jim-minter done https://github.com/openshift/source-to-image/releases/tag/1.1.4

[jim-minter]

@bparees thanks
@aelmadho please re-open if https://github.com/openshift/source-to-image/releases/tag/1.1.4 doesn't resolve your issue.