Bug 1275593

Summary: panic in HTTP server when connecting via Unix socket
Product: [Fedora] Fedora Reporter: Victor Costan <costan>
Component: dockerAssignee: Nalin Dahyabhai <nalin>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 23CC: adimania, admiller, dustymabe, dwalsh, fweimer, ichavero, jcajka, jchaloup, lsm5, maszulik, me, mgoldman, miminar, stefw, thughes, vbatts
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
URL: https://github.com/rhatdan/docker/pull/149
Whiteboard:
Fixed In Version: docker-1.8.2-14.git8f9eabc.fc23 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-11-15 00:22:50 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
In cockpit we see this
none
and this none

Description Victor Costan 2015-10-27 09:55:25 UTC 
Description of problem:
Docker panics when I have a process connect to it via a Unix socket.
The process is owned by a user in the "docker" group, and started by systemd. 
Docker does not panic when I connect to it from the same user via sudo.

Version-Release number of selected component (if applicable):
9.gitbdb52b6.fc23


How reproducible:
always

Steps to Reproduce:
I have a non-trivial reproduction scenario. All the code is open-sourced, so I can provide a full description, if it helps.
The stack trace below points to a problem in credentials_linux.go, which seems to call getpwuid with bogus pointers. Perhaps that's enough?

Actual results:

I got the following trace from my logs.
Oct 27 08:49:12 localhost.localdomain docker[2397]: time="2015-10-27T08:49:12.850209687Z" level=info msg="POST /v1.16/build?forcerm=1&t=alg_mr%2Fbase.2"
Oct 27 08:49:12 localhost.localdomain docker[2397]: 2015/10/27 08:49:12 http: panic serving @: runtime error: invalid memory address or nil pointer dereference
Oct 27 08:49:12 localhost.localdomain docker[2397]: goroutine 376 [running]:
Oct 27 08:49:12 localhost.localdomain docker[2397]: net/http.(*conn).serve.func1(0xc820ae08f0, 0x7fd5fe549a30, 0xc820026d10)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/net/http/server.go:1287 +0xb5 fp=0xc8207654d8 sp=0xc820765408
Oct 27 08:49:12 localhost.localdomain docker[2397]: runtime.call32(0x0, 0x1287a48, 0xc82000a260, 0x1800000018)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/runtime/asm_amd64.s:437 +0x3e fp=0xc820765500 sp=0xc8207654d8
Oct 27 08:49:12 localhost.localdomain docker[2397]: runtime.gopanic(0xf0f720, 0xc82000e070)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/runtime/panic.go:423 +0x4e9 fp=0xc820765580 sp=0xc820765500
Oct 27 08:49:12 localhost.localdomain docker[2397]: runtime.panicmem()
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/runtime/panic.go:42 +0x49 fp=0xc8207655a8 sp=0xc820765580
Oct 27 08:49:12 localhost.localdomain docker[2397]: runtime.sigpanic()
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/runtime/sigpanic_unix.go:24 +0x2ba fp=0xc8207655f8 sp=0xc8207655a8
Oct 27 08:49:12 localhost.localdomain docker[2397]: github.com/docker/docker/api/server.getpwuid(0xffffffff, 0x0, 0x0, 0x0, 0x0)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /builddir/build/BUILD/docker-bdb52b6c540fedd58243e3fe7ccb19dbc1be56a0/_build/src/github.com/docker/docker/api/server/credentials_linux.go:74 +0x126 fp=0xc820765678 sp=0xc8207655f8
Oct 27 08:49:12 localhost.localdomain docker[2397]: github.com/docker/docker/api/server.(*Server).LogAction(0xc820204200, 0x7fd5fe557c20, 0xc820ae0a50, 0xc8208aed20, 0x0, 0x0)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /builddir/build/BUILD/docker-bdb52b6c540fedd58243e3fe7ccb19dbc1be56a0/_build/src/github.com/docker/docker/api/server/credentials_linux.go:168 +0xaa2 fp=0xc820765850 sp=0xc820765678
Oct 27 08:49:12 localhost.localdomain docker[2397]: github.com/docker/docker/api/server.(*Server).makeHttpHandler.func1(0x7fd5fe557c20, 0xc820ae0a50, 0xc8208aed20)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /builddir/build/BUILD/docker-bdb52b6c540fedd58243e3fe7ccb19dbc1be56a0/_build/src/github.com/docker/docker/api/server/server.go:1680 +0x8aa fp=0xc820765aa8 sp=0xc820765850
Oct 27 08:49:12 localhost.localdomain docker[2397]: net/http.HandlerFunc.ServeHTTP(0xc82033e060, 0x7fd5fe557c20, 0xc820ae0a50, 0xc8208aed20)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/net/http/server.go:1422 +0x3a fp=0xc820765ac8 sp=0xc820765aa8
Oct 27 08:49:12 localhost.localdomain docker[2397]: github.com/gorilla/mux.(*Router).ServeHTTP(0xc820209a40, 0x7fd5fe557c20, 0xc820ae0a50, 0xc8208aed20)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /builddir/build/BUILD/docker-bdb52b6c540fedd58243e3fe7ccb19dbc1be56a0/vendor/src/github.com/gorilla/mux/mux.go:98 +0x29e fp=0xc820765be0 sp=0xc820765ac8
Oct 27 08:49:12 localhost.localdomain docker[2397]: net/http.serverHandler.ServeHTTP(0xc82033e0c0, 0x7fd5fe557c20, 0xc820ae0a50, 0xc8208aed20)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/net/http/server.go:1862 +0x19e fp=0xc820765c40 sp=0xc820765be0
Oct 27 08:49:12 localhost.localdomain docker[2397]: net/http.(*conn).serve(0xc820ae08f0)
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/net/http/server.go:1361 +0xbee fp=0xc820765f98 sp=0xc820765c40
Oct 27 08:49:12 localhost.localdomain docker[2397]: runtime.goexit()
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820765fa0 sp=0xc820765f98
Oct 27 08:49:12 localhost.localdomain docker[2397]: created by net/http.(*Server).Serve
Oct 27 08:49:12 localhost.localdomain docker[2397]: /usr/lib/golang/src/net/http/server.go:1910 +0x3f6

Expected results:
I should be able to connect to Docker via the Unix socket.

Additional info:
This is a regression from 22.gitdcff4e1.fc23
Comment 1 Victor Costan 2015-10-27 10:48:45 UTC 
The full docker version-release is 1.8.2-9.gitbdb52b6.fc23

Sorry!
Comment 2 Daniel Walsh 2015-10-27 13:11:42 UTC 
Looks like a bug in the credentials_linux code.  Probably something about using -1 for UID?
Comment 3 Daniel Walsh 2015-10-27 13:55:34 UTC 
BTW Hooking up the docker socket to an apache web service is incredibly risky.  Being able to talk to the docker socket is the equivalent of giving Full ROOT access to a process with no logging.

http://www.projectatomic.io/blog/2015/08/why-we-dont-let-non-root-users-run-docker-in-centos-fedora-or-rhel/
Comment 4 Nalin Dahyabhai 2015-10-27 14:31:12 UTC 
The 1.8 branch's version is missing some safety checks for cases where the client's login UID can't be determined, which is the case both for other services on the system launched by systemd (such as this one, and I expect kubernetes) and for clients connecting over TCP.
Comment 5 Daniel Walsh 2015-10-27 15:48:16 UTC 
So this should be fixed in docker-1.9?
Comment 6 Nalin Dahyabhai 2015-10-27 15:50:01 UTC 
We shouldn't be seeing it there, as we already check for that error in 1.9.
Comment 7 Daniel Walsh 2015-10-27 15:54:24 UTC 
Fixed in docker-1.9
Comment 8 Victor Costan 2015-10-27 19:09:58 UTC 
Re: security -- yup, I read that. Hence I filed the bug, rather than just using HTTP(S) and moving on with my life :)

Re: 1.9 -- currently (as of last night), 1.7 is in stable for Fedora 23. When the 1.8.2 package gets promoted to stable, it might break other people who relied on the same configuration. Is there a 1.9 package out that I can try / switch to?

Thank you!
Comment 9 Daniel Walsh 2015-10-27 20:54:35 UTC 
Not yet.  Hopefully within a week.  Not quite released by docker yet.
Comment 10 Victor Costan 2015-10-27 20:58:11 UTC 
It would be really nice to have an rc in testing!

The release/1.9 branch in Docker seems to have quieted down, and I doubt they'll take in too many patches between now and Thursday.
Comment 11 Daniel Walsh 2015-10-28 12:28:50 UTC 
We are building docker-1.9.0-rc3 into rawhide now.  I agree Docker is scheduled to release this week.
Comment 12 Victor Costan 2015-10-28 12:33:28 UTC 
Thank you! I look forward to trying it out!
Comment 13 Marek Goldmann 2015-11-04 11:38:14 UTC 
I see this when I run a CentOS 7 container on a Fedora 23 host and try to run docker in docker with mounted socket.
Comment 14 Nalin Dahyabhai 2015-11-05 18:13:47 UTC 
Marek, what's the version of the docker package that provides the binary that's crashing for you?  Is it the version and binary in the CentOS 7 container, or on the Fedora 23 host?
Comment 15 Marek Goldmann 2015-11-06 08:52:47 UTC 
It's on the Fedora 23 host, using latest from updates-testing: docker-1.8.2-10.git28c300f.fc23.x86_64, but it happened on docker-1.8.2-9.gitbdb52b6.fc23 too. 

Run:

docker run -it --rm --privileged -v /var/run/docker.sock:/var/run/docker.sock centos:7

Then install docker:

$ yum -y install docker

Then run docker ps:

[root@99e8b8872fcc /]# docker ps
Get http:///var/run/docker.sock/v1.20/containers/json: EOF.
* Are you trying to connect to a TLS-enabled daemon without TLS?
* Is your docker daemon up and running?

Watch systemd docker unit logs on the fedora host:

Nov 06 09:52:09 mistress docker[17060]: time="2015-11-06T09:52:09.135154219+01:00" level=info msg="GET /v1.20/containers/json"
Nov 06 09:52:09 mistress docker[17060]: 2015/11/06 09:52:09 http: panic serving @: runtime error: invalid memory address or nil pointer dereference
Nov 06 09:52:09 mistress docker[17060]: goroutine 1071 [running]:
Nov 06 09:52:09 mistress docker[17060]: net/http.(*conn).serve.func1(0xc8209eadc0, 0x7fd680100998, 0xc8206a4158)
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/net/http/server.go:1287 +0xb5 fp=0xc82162f4c8 sp=0xc82162f3f8
Nov 06 09:52:09 mistress docker[17060]: runtime.call32(0x0, 0x1287be8, 0xc82011c3f0, 0x1800000018)
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/runtime/asm_amd64.s:437 +0x3e fp=0xc82162f4f0 sp=0xc82162f4c8
Nov 06 09:52:09 mistress docker[17060]: runtime.gopanic(0xf0f880, 0xc82000e070)
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/runtime/panic.go:423 +0x4e9 fp=0xc82162f570 sp=0xc82162f4f0
Nov 06 09:52:09 mistress docker[17060]: runtime.panicmem()
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/runtime/panic.go:42 +0x49 fp=0xc82162f598 sp=0xc82162f570
Nov 06 09:52:09 mistress docker[17060]: runtime.sigpanic()
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/runtime/sigpanic_unix.go:24 +0x2ba fp=0xc82162f5e8 sp=0xc82162f598
Nov 06 09:52:09 mistress docker[17060]: github.com/docker/docker/api/server.getpwuid(0xffffffff, 0x0, 0x0, 0x0, 0x0)
Nov 06 09:52:09 mistress docker[17060]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/credentials_linux.go:75 +0x1f6 fp=0xc82162f678 sp=0xc82162f5e8
Nov 06 09:52:09 mistress docker[17060]: github.com/docker/docker/api/server.(*Server).LogAction(0xc820235640, 0x7fd680080120, 0xc8209eae70, 0xc8208a41c0, 0x0, 0x0)
Nov 06 09:52:09 mistress docker[17060]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/credentials_linux.go:172 +0xaac fp=0xc82162f850 sp=0xc82162f678
Nov 06 09:52:09 mistress docker[17060]: github.com/docker/docker/api/server.(*Server).makeHttpHandler.func1(0x7fd680080120, 0xc8209eae70, 0xc8208a41c0)
Nov 06 09:52:09 mistress docker[17060]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/server.go:1680 +0x8aa fp=0xc82162faa8 sp=0xc82162f850
Nov 06 09:52:09 mistress docker[17060]: net/http.HandlerFunc.ServeHTTP(0xc82029fe60, 0x7fd680080120, 0xc8209eae70, 0xc8208a41c0)
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/net/http/server.go:1422 +0x3a fp=0xc82162fac8 sp=0xc82162faa8
Nov 06 09:52:09 mistress docker[17060]: github.com/gorilla/mux.(*Router).ServeHTTP(0xc82026f8b0, 0x7fd680080120, 0xc8209eae70, 0xc8208a41c0)
Nov 06 09:52:09 mistress docker[17060]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/vendor/src/github.com/gorilla/mux/mux.go:98 +0x29e fp=0xc82162fbe0 sp=0xc82162fac8
Nov 06 09:52:09 mistress docker[17060]: net/http.serverHandler.ServeHTTP(0xc8203f4060, 0x7fd680080120, 0xc8209eae70, 0xc8208a41c0)
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/net/http/server.go:1862 +0x19e fp=0xc82162fc40 sp=0xc82162fbe0
Nov 06 09:52:09 mistress docker[17060]: net/http.(*conn).serve(0xc8209eadc0)
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/net/http/server.go:1361 +0xbee fp=0xc82162ff98 sp=0xc82162fc40
Nov 06 09:52:09 mistress docker[17060]: runtime.goexit()
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc82162ffa0 sp=0xc82162ff98
Nov 06 09:52:09 mistress docker[17060]: created by net/http.(*Server).Serve
Nov 06 09:52:09 mistress docker[17060]: /usr/lib/golang/src/net/http/server.go:1910 +0x3f6
Comment 16 Tim Hughes 2015-11-07 00:49:52 UTC 
You are right about the kubernetes, I am seeing it with these revisions


[root@titanium ~]# rpm -qa |grep docker
docker-1.8.2-10.git28c300f.fc23.x86_64h
docker-selinux-1.8.2-10.git28c300f.fc23.x86_64
cockpit-docker-0.83-1.fc23.x86_64
[root@titanium ~]# rpm -qa |grep kube
cockpit-kubernetes-0.83-1.fc23.x86_64
kubernetes-client-1.1.0-0.5.gite44c8e6.fc23.x86_64
kubernetes-master-1.1.0-0.5.gite44c8e6.fc23.x86_64
kubernetes-node-1.1.0-0.5.gite44c8e6.fc23.x86_64





[root@titanium ~]# systemctl restart docker.service
[root@titanium ~]# journalctl  --unit=docker -f
-- Logs begin at Thu 2015-04-09 20:36:53 BST. --
Nov 07 00:41:57 titanium.co.goldfish docker[12628]: goroutine 3687 [running]:
Nov 07 00:41:57 titanium.co.goldfish docker[12628]: net/http.(*conn).serve.func1(0xc8203e22c0, 0x7f3e15425310, 0xc82019a038)
Nov 07 00:41:57 titanium.co.goldfish docker[12628]: /usr/lib/golang/src/net/http/server.go:1287 +0xb5 fp=0xc8204514c8 sp=0xc8204513f8
Nov 07 00:41:57 titanium.co.goldfish docker[12628]: runtime.call32(0x0, 0x1287be8, 0xc820512440, 0x1800000018)
Nov 07 00:41:57 titanium.co.goldfish docker[12628]: /usr/lib/golang/src/runtime/asm_amd64.s:437 +0x3e fp=0xc8204514f0 sp=0xc8204514c8
Nov 07 00:41:57 titanium.co.goldfish docker[12628]: runtime.gopanic(0xf0f880, 0xc82000e070)
Nov 07 00:41:57 titanium.co.goldfish docker[12628]: /usr/lib/golang/src/runtime/panic.go:423 +0x4e9 fp=0xc820451570 sp=0xc8204514f0
Nov 07 00:42:02 titanium.co.goldfish systemd[1]: Stopping Docker Application Container Engine...
Nov 07 00:42:02 titanium.co.goldfish systemd[1]: Starting Docker Application Container Engine...
Nov 07 00:42:03 titanium.co.goldfish systemd[1]: Started Docker Application Container Engine.
FNov 07 00:42:24 titanium.co.goldfish docker[14398]: time="2015-11-07T00:42:24.388047681Z" level=info msg="GET /version"
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: 2015/11/07 00:42:24 http: panic serving @: runtime error: invalid memory address or nil pointer dereference
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: goroutine 224 [running]:
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: net/http.(*conn).serve.func1(0xc820519290, 0x7f0da2d94228, 0xc82011a170)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/net/http/server.go:1287 +0xb5 fp=0xc8205bb4c8 sp=0xc8205bb3f8
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: runtime.call32(0x0, 0x1287be8, 0xc820514800, 0x1800000018)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/runtime/asm_amd64.s:437 +0x3e fp=0xc8205bb4f0 sp=0xc8205bb4c8
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: runtime.gopanic(0xf0f880, 0xc82000e070)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/runtime/panic.go:423 +0x4e9 fp=0xc8205bb570 sp=0xc8205bb4f0
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: runtime.panicmem()
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/runtime/panic.go:42 +0x49 fp=0xc8205bb598 sp=0xc8205bb570
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: runtime.sigpanic()
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/runtime/sigpanic_unix.go:24 +0x2ba fp=0xc8205bb5e8 sp=0xc8205bb598
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: github.com/docker/docker/api/server.getpwuid(0xffffffff, 0x0, 0x0, 0x0, 0x0)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/credentials_linux.go:75 +0x1f6 fp=0xc8205bb678 sp=0xc8205bb5e8
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: github.com/docker/docker/api/server.(*Server).LogAction(0xc8200115c0, 0x7f0da1511d78, 0xc820519340, 0xc82015ce00, 0x0, 0x0)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/credentials_linux.go:172 +0xaac fp=0xc8205bb850 sp=0xc8205bb678
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: github.com/docker/docker/api/server.(*Server).makeHttpHandler.func1(0x7f0da1511d78, 0xc820519340, 0xc82015ce00)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/server.go:1680 +0x8aa fp=0xc8205bbaa8 sp=0xc8205bb850
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: net/http.HandlerFunc.ServeHTTP(0xc820376840, 0x7f0da1511d78, 0xc820519340, 0xc82015ce00)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/net/http/server.go:1422 +0x3a fp=0xc8205bbac8 sp=0xc8205bbaa8
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: github.com/gorilla/mux.(*Router).ServeHTTP(0xc82028af00, 0x7f0da1511d78, 0xc820519340, 0xc82015ce00)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/vendor/src/github.com/gorilla/mux/mux.go:98 +0x29e fp=0xc8205bbbe0 sp=0xc8205bbac8
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: net/http.serverHandler.ServeHTTP(0xc8201c6540, 0x7f0da1511d78, 0xc820519340, 0xc82015ce00)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/net/http/server.go:1862 +0x19e fp=0xc8205bbc40 sp=0xc8205bbbe0
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: net/http.(*conn).serve(0xc820519290)
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/net/http/server.go:1361 +0xbee fp=0xc8205bbf98 sp=0xc8205bbc40
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: runtime.goexit()
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc8205bbfa0 sp=0xc8205bbf98
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: created by net/http.(*Server).Serve
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: /usr/lib/golang/src/net/http/server.go:1910 +0x3f6
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: time="2015-11-07T00:42:24.489275676Z" level=info msg="GET /version"
Nov 07 00:42:24 titanium.co.goldfish docker[14398]: 2015/11/07 00:42:24 http: panic serving @: runtime error: invalid memory address or nil pointer dereference
Comment 17 Tim Hughes 2015-11-07 00:53:41 UTC 
Created attachment 1090817 [details]
In cockpit we see this
Comment 18 Tim Hughes 2015-11-07 00:55:10 UTC 
Created attachment 1090818 [details]
and this
Comment 19 Maciej Szulik 2015-11-10 21:54:22 UTC 
*** Bug 1279923 has been marked as a duplicate of this bug. ***
Comment 20 Victor Costan 2015-11-11 07:49:31 UTC 
The build that's causing this got promoted to stable, so I have to do some workarounds.

The currently stable version [1] is using a commit [2] that claims to fix this bug [3]. However, I'm still seeing the bug (stacktrace at the bottom).

Perhaps libc's getpwuid (C.getpwuid) doesn't set errno, so the go getpwuid() should also check if the structure is nil?
Alternatively, would it be possible to just nix displaying the username in the logs? It is convenient to have it, but it's not worth crashes.

Thank you!

[1] https://bodhi.fedoraproject.org/updates/FEDORA-2015-7e1a61e141
[2] https://github.com/rhatdan/docker/commit/28c300fafb58c380d78381e08e1be35dfed5d4f9
[3] https://github.com/rhatdan/docker/pull/149

Nov 11 07:24:01 localhost.localdomain docker[4772]: 2015/11/11 07:24:01 http: panic serving @: runtime error: invalid memory address or nil pointer dereference
Nov 11 07:24:01 localhost.localdomain docker[4772]: goroutine 67 [running]:
Nov 11 07:24:01 localhost.localdomain docker[4772]: net/http.(*conn).serve.func1(0xc8200ce0b0, 0x7f696a8f08a0, 0xc820026a30)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/net/http/server.go:1287 +0xb5 fp=0xc8200494c8 sp=0xc8200493f8
Nov 11 07:24:01 localhost.localdomain docker[4772]: runtime.call32(0x0, 0x1287be8, 0xc82000a260, 0x1800000018)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/runtime/asm_amd64.s:437 +0x3e fp=0xc8200494f0 sp=0xc8200494c8
Nov 11 07:24:01 localhost.localdomain docker[4772]: runtime.gopanic(0xf0f880, 0xc82000e070)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/runtime/panic.go:423 +0x4e9 fp=0xc820049570 sp=0xc8200494f0
Nov 11 07:24:01 localhost.localdomain docker[4772]: runtime.panicmem()
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/runtime/panic.go:42 +0x49 fp=0xc820049598 sp=0xc820049570
Nov 11 07:24:01 localhost.localdomain docker[4772]: runtime.sigpanic()
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/runtime/sigpanic_unix.go:24 +0x2ba fp=0xc8200495e8 sp=0xc820049598
Nov 11 07:24:01 localhost.localdomain docker[4772]: github.com/docker/docker/api/server.getpwuid(0xffffffff, 0x0, 0x0, 0x0, 0x0)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/credentials_linux.go:75 +0x1f6 fp=0xc820049678 sp=0xc8200495e8
Nov 11 07:24:01 localhost.localdomain docker[4772]: github.com/docker/docker/api/server.(*Server).LogAction(0xc820190140, 0x7f696a8fb370, 0xc8200ce160, 0xc820084d20, 0x0, 0x0)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/credentials_linux.go:172 +0xaac fp=0xc820049850 sp=0xc820049678
Nov 11 07:24:01 localhost.localdomain docker[4772]: github.com/docker/docker/api/server.(*Server).makeHttpHandler.func1(0x7f696a8fb370, 0xc8200ce160, 0xc820084d20)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/_build/src/github.com/docker/docker/api/server/server.go:1680 +0x8aa fp=0xc820049aa8 sp=0xc820049850
Nov 11 07:24:01 localhost.localdomain docker[4772]: net/http.HandlerFunc.ServeHTTP(0xc82024d440, 0x7f696a8fb370, 0xc8200ce160, 0xc820084d20)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/net/http/server.go:1422 +0x3a fp=0xc820049ac8 sp=0xc820049aa8
Nov 11 07:24:01 localhost.localdomain docker[4772]: github.com/gorilla/mux.(*Router).ServeHTTP(0xc820201a40, 0x7f696a8fb370, 0xc8200ce160, 0xc820084d20)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /builddir/build/BUILD/docker-28c300fafb58c380d78381e08e1be35dfed5d4f9/vendor/src/github.com/gorilla/mux/mux.go:98 +0x29e fp=0xc820049be0 sp=0xc820049ac8
Nov 11 07:24:01 localhost.localdomain docker[4772]: net/http.serverHandler.ServeHTTP(0xc820339f80, 0x7f696a8fb370, 0xc8200ce160, 0xc820084d20)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/net/http/server.go:1862 +0x19e fp=0xc820049c40 sp=0xc820049be0
Nov 11 07:24:01 localhost.localdomain docker[4772]: net/http.(*conn).serve(0xc8200ce0b0)
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/net/http/server.go:1361 +0xbee fp=0xc820049f98 sp=0xc820049c40
Nov 11 07:24:01 localhost.localdomain docker[4772]: runtime.goexit()
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/runtime/asm_amd64.s:1696 +0x1 fp=0xc820049fa0 sp=0xc820049f98
Nov 11 07:24:01 localhost.localdomain docker[4772]: created by net/http.(*Server).Serve
Nov 11 07:24:01 localhost.localdomain docker[4772]: /usr/lib/golang/src/net/http/server.go:1910 +0x3f6
Comment 21 Victor Costan 2015-11-11 09:11:25 UTC 
Last, for folks getting hit by this, one workaround is versionlocking on docker-1.8.2-7.gitcb216be.fc23, which is the last working build.

dnf install fedora-packager
mkdir docker
cd docker
koji download-build docker-1.8.2-7.gitcb216be.fc23
dnf install docker-1.8.2-7.gitcb216be.fc23.x86_64.rpm docker-vim-1.8.2-7.gitcb216be.fc23.x86_64.rpm docker-logrotate-1.8.2-7.gitcb216be.fc23.x86_64.rpm docker-selinux-1.8.2-7.gitcb216be.fc23.x86_64.rpm docker-fish-completion-1.8.2-7.gitcb216be.fc23.x86_64.rpm docker-zsh-completion-1.8.2-7.gitcb216be.fc23.x86_64.rpm
cd ..
rm -r docker
Comment 22 Florian Weimer 2015-11-11 15:16:56 UTC 
(In reply to Victor Costan from comment #20)
> The build that's causing this got promoted to stable, so I have to do some
> workarounds.
> 
> The currently stable version [1] is using a commit [2] that claims to fix
> this bug [3]. However, I'm still seeing the bug (stacktrace at the bottom).
> 
> Perhaps libc's getpwuid (C.getpwuid) doesn't set errno, so the go getpwuid()
> should also check if the structure is nil?

getwpuid is not thread-safe, and the returned pointer is reused for the next call to getpwuid.  Internally, this goes through __fgetpwent_r, and this function calls parse_line, which clears the pw_name member:

  https://sourceware.org/git/?p=glibc.git;a=blob;f=manual/pwd/fgetpwent_r.c;h=d53751618615c9ef122a3b2f15be11ace49b6e98;hb=HEAD

You need to use getpwuid_r, probably with a C wrapper.
Comment 23 Victor Costan 2015-11-11 15:54:49 UTC 
Given what Florian said, can we please get a build that nixes the uid -> name resolution functionality?

I'm currently getting crashes with the stable docker version (1.8.2-10) simply by trying to use it from the systemd unit below. The docker daemon crashes at the ExecStartPre command that pulls the image, so the ExecStart command might not be relevant.

-- unit below --
[Unit]
Description=Docker Swarm Master
After=docker.service skydns-update
Requires=docker.service
Wants=skydns-update

[Service]
Type=simple
TimeoutStartSec=0
ExecStartPre=-/usr/bin/docker kill docker-swarm-master
ExecStartPre=-/usr/bin/docker rm docker-swarm-master
ExecStartPre=/usr/bin/docker pull swarm
ExecStart=/usr/bin/docker run --name docker-swarm-master --publish=3376:2375 \
    --volume=/etc/docker-swarm-master:/etc/docker-swarm swarm manage \
    --advertise=swarm-master1.skydns.local:3376 \
    --cluster-driver=swarm --strategy=spread --filter=health --filter=port \
    --filter=affinity --filter=constraint --filter=dependency \
    --tlsverify --tlscacert=/etc/docker-swarm/ca.pem \
    --tlskey=/etc/docker-swarm/key.pem --tlscert=/etc/docker-swarm/cert.pem \
    --host=tcp://0.0.0.0:2375 file:///etc/docker-swarm/cluster
Restart=always
StandardInput=null
StandardOutput=syslog
StandardError=syslog
KillMode=process

[Install]
WantedBy=multi-user.target
Comment 24 Nalin Dahyabhai 2015-11-11 18:57:55 UTC 
Any chance you could give http://koji.fedoraproject.org/koji/taskinfo?taskID=11796353 a try?  It incorporates the patch from pull 151, which adds more fixes that we ran across while running integration tests.
Comment 25 Victor Costan 2015-11-11 21:04:11 UTC 
The koji build did the trick for me. Thank you very much, Nalin!

Is there any chance you could turn this into an update? I'm a bit worried about having to rely on a scratch build.

FWIW, the log line below might also show why #149 isn't working. More specifically, the comparison with -1 might not have been working as intended.

Nov 11 19:24:15 localhost.localdomain docker[2417]: time="2015-11-11T19:24:15.581279437Z" level=error msg="Failed to get pwuid struct for UID 4294967295: strconv.ParseInt: parsing \"%!u(int=4294967295)\": invalid syntax"
Comment 26 Dusty Mabe 2015-11-12 17:46:33 UTC 
As victor pointed out: this looks similar to: https://bugzilla.redhat.com/show_bug.cgi?id=1278984
Comment 27 Dusty Mabe 2015-11-12 20:00:32 UTC 
Koji build also works for me when running atomicapps/nulecules. Can we get this into an update and pushed to testing so we can get a wider audience to test?
Comment 28 Stef Walter 2015-11-13 09:23:37 UTC 
As one might imagine, this is breaking the Cockpit integration tests.
Comment 29 Stef Walter 2015-11-13 09:33:39 UTC 
Cockpit tracker issue: https://github.com/cockpit-project/cockpit/issues/3156
Comment 30 Fedora Update System 2015-11-13 18:56:41 UTC 
docker-1.8.2-14.git8f9eabc.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2015-ff5f31a73a
Comment 31 Daniel Walsh 2015-11-13 19:00:00 UTC 
Please test and update karma.
Comment 32 Victor Costan 2015-11-13 22:32:27 UTC 
Done. Thank you very much for the bugfix, Nalin and Daniel!
Comment 33 Fedora Update System 2015-11-14 04:52:43 UTC 
docker-1.8.2-14.git8f9eabc.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update docker'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-ff5f31a73a
Comment 34 Fedora Update System 2015-11-15 00:22:41 UTC 
docker-1.8.2-14.git8f9eabc.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.
Comment 35 Dusty Mabe 2015-11-16 17:22:58 UTC 
*** Bug 1278984 has been marked as a duplicate of this bug. ***