moby: "image not found" halfway through docker pull

Description

When pulling from a private registry (running the latest v2 registry), the pull gets most of the way there and then dies mysteriously, every time:

coderpad@execute3:~$ docker pull -a hub.coderpad.io/coderpad
...
perl: Pulling from hub.coderpad.io/coderpad
4b4d6fa67d21: Already exists
972e8d7e076b: Already exists
e1526bd2745d: Already exists
26d11c56e286: Already exists
97f1d11eb160: Already exists
Digest: sha256:744a496d8773760796bc317792b271651d2dfcbc93b15aaef74bdb3819e6a434
objc: Pulling from hub.coderpad.io/coderpad
77de9815019d: Download complete
e4e1081b8d5d: Download complete
dc0d133b4e06: Download complete
6f9f208baeb5: Download complete
360dda2dfb97: Download complete
74a1f35506d4: Download complete
e04d05f3c7e5: Downloading [>                                                  ] 540.3 kB/90.56 MB
e04d05f3c7e5: Downloading [>                                                  ] 1.081 MB/90.56 MB
beef2a74f08c: Download complete
44e66553688d: Download complete
7804f7c6f157: Downloading [=====>                                             ] 491.1 kB/4.347 MB
7804f7c6f157: Downloading [============>                                      ]  1.13 MB/4.347 MB
a8ac65ee0e65: Download complete
dab9c39627c1: Already exists
Pulling repository hub.coderpad.io/coderpad
Error: image coderpad: not found

Info

docker version:

Client version: 1.7.1
Client API version: 1.19
Go version (client): go1.4.2
Git commit (client): 786b29d
OS/Arch (client): linux/amd64
Server version: 1.7.1
Server API version: 1.19
Go version (server): go1.4.2
Git commit (server): 786b29d
OS/Arch (server): linux/amd64

docker info:

Containers: 0
Images: 67
Storage Driver: overlay
 Backing Filesystem: extfs
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 3.19.0-23-generic
Operating System: Ubuntu 14.04.2 LTS
CPUs: 8
Total Memory: 15.65 GiB
Name: execute3
ID: HHCK:GTFX:ADQE:5X6T:ZR3Q:DBKK:IOCI:BO4M:QT2V:25KK:6XOO:Q4YG
WARNING: No swap limit support

uname -a:

Linux execute3 3.19.0-23-generic #24~14.04.1-Ubuntu SMP Wed Jul 8 11:15:13 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

Environment details (AWS, VirtualBox, physical, etc.):

Physical server in SoftLayer.

How reproducible:

100% of the time pulling this particular image. Doesn’t seem to happen on other hosts, though. Logging out and back in does not seem to help.

Here are some logs from /var/log/upstart/docker.log. They suggest that this is some strange auth issue.

INFO[0000] Loading containers: done.
INFO[0000] Daemon has completed initialization
INFO[0000] Docker daemon                                 commit=786b29d execdriver=native-0.2 graphdriver=overlay version=1.7.1
INFO[0048] GET /v1.19/version
INFO[0060] GET /v1.19/info
INFO[0541] GET /v1.19/version
INFO[0679] POST /v1.19/images/create?fromImage=hub.coderpad.io%2Fcoderpad
ERRO[0679] Error from V2 registry: Authentication is required.
INFO[0683] POST /v1.19/images/create?fromImage=hub.coderpad.io%2Fcoderpad
ERRO[0683] Error from V2 registry: Authentication is required.
INFO[0697] POST /v1.19/images/create?fromImage=hub.coderpad.io%2Fcoderpad
ERRO[0697] Error from V2 registry: symlink ld.so.8.gz /var/lib/docker/overlay/77de9815019d2f9dff1321a30b5731fa05bf56d90109e543ab4332a929010304/tmproot806036716/usr/share/man/man8/ld-linux.so.8.gz: no space left on device
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x20 pc=0x62fc6a]

goroutine 235 [running]:
bufio.(*Writer).flush(0xc2082051c0, 0x0, 0x0)
    /usr/local/go/src/bufio/bufio.go:530 +0xda
bufio.(*Writer).Flush(0xc2082051c0, 0x0, 0x0)
    /usr/local/go/src/bufio/bufio.go:519 +0x3a
net/http.(*response).Flush(0xc20848df40)
    /usr/local/go/src/net/http/server.go:1047 +0x4c
github.com/docker/docker/pkg/ioutils.(*WriteFlusher).Write(0xc2082089f0, 0xc2083c1b80, 0xba, 0x148, 0xba, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/ioutils/writeflusher.go:21 +0x145
github.com/docker/docker/pkg/progressreader.(*Config).Read(0xc2084aa0e0, 0xc208766000, 0x8000, 0x8000, 0x4000, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/progressreader/progressreader.go:37 +0x2e5
io.Copy(0x7f00cb86a2a8, 0xc208037538, 0x7f00cb87f028, 0xc2084aa0e0, 0x97e8c, 0x0, 0x0)
    /usr/local/go/src/io/io.go:362 +0x1f6
github.com/docker/docker/graph.func·008(0xc2083e2bf0, 0x0, 0x0)
    /go/src/github.com/docker/docker/graph/pull.go:602 +0xd42
github.com/docker/docker/graph.func·009(0xc2083e2bf0)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x2f
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 1 [chan receive, 10 minutes]:
main.mainDaemon()
    /go/src/github.com/docker/docker/docker/daemon.go:179 +0x10a8
main.main()
    /go/src/github.com/docker/docker/docker/docker.go:93 +0x6b4

goroutine 5 [syscall, 11 minutes]:
os/signal.loop()
    /usr/local/go/src/os/signal/signal_unix.go:21 +0x1f
created by os/signal.init·1
    /usr/local/go/src/os/signal/signal_unix.go:27 +0x35

goroutine 17 [syscall, 11 minutes, locked to thread]:
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:2232 +0x1

goroutine 10 [IO wait]:
net.(*pollDesc).Wait(0xc208156f40, 0x72, 0x0, 0x0)
    /usr/local/go/src/net/fd_poll_runtime.go:84 +0x47
net.(*pollDesc).WaitRead(0xc208156f40, 0x0, 0x0)
    /usr/local/go/src/net/fd_poll_runtime.go:89 +0x43
net.(*netFD).accept(0xc208156ee0, 0x0, 0x7f00cb86a1a0, 0xc2082e8db0)
    /usr/local/go/src/net/fd_unix.go:419 +0x40b
net.(*UnixListener).AcceptUnix(0xc2080e1760, 0xc20827e4c0, 0x0, 0x0)
    /usr/local/go/src/net/unixsock_posix.go:282 +0x56
net.(*UnixListener).Accept(0xc2080e1760, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/unixsock_posix.go:293 +0x4c
github.com/docker/docker/pkg/listenbuffer.(*defaultListener).Accept(0xc2080e17e0, 0x0, 0x0, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/listenbuffer/buffer.go:71 +0x67
net/http.(*Server).Serve(0xc208108f60, 0x7f00cb8719a8, 0xc2080e17e0, 0x0, 0x0)
    /usr/local/go/src/net/http/server.go:1728 +0x92
github.com/docker/docker/api/server.(*HttpServer).Serve(0xc2080e1940, 0x0, 0x0)
    /go/src/github.com/docker/docker/api/server/server.go:128 +0x4d
github.com/docker/docker/api/server.func·002(0x7f00cb871a08, 0xc2080e1940)
    /go/src/github.com/docker/docker/api/server/server.go:104 +0x40
created by github.com/docker/docker/api/server.(*Server).ServeApi
    /go/src/github.com/docker/docker/api/server/server.go:108 +0x6ac

goroutine 9 [chan receive, 11 minutes]:
github.com/docker/docker/api/server.(*Server).ServeApi(0xc20800a740, 0xc2080ac5b0, 0x1, 0x1, 0x0, 0x0)
    /go/src/github.com/docker/docker/api/server/server.go:113 +0x74f
main.func·003()
    /go/src/github.com/docker/docker/docker/daemon.go:129 +0x5f
created by main.mainDaemon
    /go/src/github.com/docker/docker/docker/daemon.go:135 +0x6b6

goroutine 11 [chan receive, 11 minutes]:
github.com/docker/docker/daemon.func·021()
    /go/src/github.com/docker/docker/daemon/debugtrap.go:17 +0x5c
created by github.com/docker/docker/daemon.setupSigusr1Trap
    /go/src/github.com/docker/docker/daemon/debugtrap.go:20 +0x18e

goroutine 36 [chan receive, 10 minutes]:
database/sql.(*DB).connectionOpener(0xc20821cbe0)
    /usr/local/go/src/database/sql/sql.go:589 +0x4c
created by database/sql.Open
    /usr/local/go/src/database/sql/sql.go:452 +0x31c

goroutine 40 [chan receive, 10 minutes]:
github.com/docker/docker/pkg/signal.func·002()
    /go/src/github.com/docker/docker/pkg/signal/trap.go:29 +0x8f
created by github.com/docker/docker/pkg/signal.Trap
    /go/src/github.com/docker/docker/pkg/signal/trap.go:55 +0x250

goroutine 39 [chan receive]:
github.com/docker/docker/daemon.(*statsCollector).run(0xc2081d6150)
    /go/src/github.com/docker/docker/daemon/stats_collector.go:89 +0xb2
created by github.com/docker/docker/daemon.newStatsCollector
    /go/src/github.com/docker/docker/daemon/stats_collector.go:29 +0x116

goroutine 49 [sleep]:
net.func·019()
    /usr/local/go/src/net/dnsclient_unix.go:240 +0x5a
created by net.loadConfig
    /usr/local/go/src/net/dnsclient_unix.go:269 +0x20c

goroutine 226 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2ec0)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 227 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2e70)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 228 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2e20)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 229 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2dd0)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 230 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2d80)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 231 [IO wait]:
net.(*pollDesc).Wait(0xc20823b870, 0x72, 0x0, 0x0)
    /usr/local/go/src/net/fd_poll_runtime.go:84 +0x47
net.(*pollDesc).WaitRead(0xc20823b870, 0x0, 0x0)
    /usr/local/go/src/net/fd_poll_runtime.go:89 +0x43
net.(*netFD).Read(0xc20823b810, 0xc20876054a, 0x5ab6, 0x5ab6, 0x0, 0x7f00cb86a1a0, 0xc208392fe0)
    /usr/local/go/src/net/fd_unix.go:242 +0x40f
net.(*conn).Read(0xc208036970, 0xc20876054a, 0x5ab6, 0x5ab6, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/net.go:121 +0xdc
github.com/docker/docker/pkg/timeoutconn.(*conn).Read(0xc2083027e0, 0xc20876054a, 0x5ab6, 0x5ab6, 0x5a8, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/timeoutconn/timeoutconn.go:24 +0x17b
crypto/tls.(*block).readFromUntil(0xc208170ab0, 0x7f00cb878cd8, 0xc2083027e0, 0x401d, 0x0, 0x0)
    /usr/local/go/src/crypto/tls/conn.go:454 +0xe6
crypto/tls.(*Conn).readRecord(0xc20847f600, 0x17, 0x0, 0x0)
    /usr/local/go/src/crypto/tls/conn.go:586 +0xc60
crypto/tls.(*Conn).Read(0xc20847f600, 0xc208580000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/go/src/crypto/tls/conn.go:904 +0x166
net/http.noteEOFReader.Read(0x7f00cb878628, 0xc20847f600, 0xc20859e528, 0xc208580000, 0x8000, 0x8000, 0x4000, 0x0, 0x0)
    /usr/local/go/src/net/http/transport.go:1270 +0x6e
net/http.(*noteEOFReader).Read(0xc2083b8040, 0xc208580000, 0x8000, 0x8000, 0x4000, 0x0, 0x0)
    <autogenerated>:125 +0xd4
bufio.(*Reader).Read(0xc2081ed200, 0xc208580000, 0x8000, 0x8000, 0x4000, 0x0, 0x0)
    /usr/local/go/src/bufio/bufio.go:164 +0x13a
io.(*LimitedReader).Read(0xc20825a2e0, 0xc208580000, 0x8000, 0x8000, 0x4207ba, 0x0, 0x0)
    /usr/local/go/src/io/io.go:408 +0xce
net/http.(*body).readLocked(0xc20847a840, 0xc208580000, 0x8000, 0x8000, 0xffffffff, 0x0, 0x0)
    /usr/local/go/src/net/http/transfer.go:584 +0x7a
net/http.(*body).Read(0xc20847a840, 0xc208580000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/http/transfer.go:579 +0x115
net/http.(*bodyEOFSignal).Read(0xc20847a880, 0xc208580000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/http/transport.go:1193 +0x285
github.com/docker/docker/pkg/transport.(*OnEOFReader).Read(0xc20825ab60, 0xc208580000, 0x8000, 0x8000, 0x8, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/transport/transport.go:130 +0x77
github.com/docker/docker/pkg/transport.(*OnEOFReader).Read(0xc20825aba0, 0xc208580000, 0x8000, 0x8000, 0x8, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/transport/transport.go:130 +0x77
github.com/docker/docker/pkg/transport.(*OnEOFReader).Read(0xc20825ac00, 0xc208580000, 0x8000, 0x8000, 0xc208597a70, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/transport/transport.go:130 +0x77
io.(*teeReader).Read(0xc20825ac60, 0xc208580000, 0x8000, 0x8000, 0x8, 0x0, 0x0)
    /usr/local/go/src/io/io.go:495 +0x83
io/ioutil.(*nopCloser).Read(0xc208381750, 0xc208580000, 0x8000, 0x8000, 0xc208392fa8, 0x0, 0x0)
    <autogenerated>:4 +0x89
github.com/docker/docker/pkg/progressreader.(*Config).Read(0xc2084aa070, 0xc208580000, 0x8000, 0x8000, 0x4000, 0x0, 0x0)
    /go/src/github.com/docker/docker/pkg/progressreader/progressreader.go:27 +0x8e
io.Copy(0x7f00cb86a2a8, 0xc2080373d8, 0x7f00cb87f028, 0xc2084aa070, 0xe3e8b, 0x0, 0x0)
    /usr/local/go/src/io/io.go:362 +0x1f6
github.com/docker/docker/graph.func·008(0xc2083e2d30, 0x0, 0x0)
    /go/src/github.com/docker/docker/graph/pull.go:602 +0xd42
github.com/docker/docker/graph.func·009(0xc2083e2d30)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x2f
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 232 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2ce0)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 233 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2c90)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 234 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2c40)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 236 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2ba0)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 237 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2b50)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 238 [chan send]:
github.com/docker/docker/graph.func·009(0xc2083e2b00)
    /go/src/github.com/docker/docker/graph/pull.go:626 +0x6b
created by github.com/docker/docker/graph.(*TagStore).pullV2Tag
    /go/src/github.com/docker/docker/graph/pull.go:627 +0x2671

goroutine 283 [runnable]:
net/http.(*persistConn).readLoop(0xc20859e790)
    /usr/local/go/src/net/http/transport.go:928 +0x9ce
created by net/http.(*Transport).dialConn
    /usr/local/go/src/net/http/transport.go:660 +0xc9f

goroutine 280 [select]:
net/http.(*persistConn).writeLoop(0xc20859e4d0)
    /usr/local/go/src/net/http/transport.go:945 +0x41d
created by net/http.(*Transport).dialConn
    /usr/local/go/src/net/http/transport.go:661 +0xcbc

goroutine 279 [select]:
net/http.(*persistConn).readLoop(0xc20859e4d0)
    /usr/local/go/src/net/http/transport.go:928 +0x9ce
created by net/http.(*Transport).dialConn
    /usr/local/go/src/net/http/transport.go:660 +0xc9f

goroutine 284 [select]:
net/http.(*persistConn).writeLoop(0xc20859e790)
    /usr/local/go/src/net/http/transport.go:945 +0x41d
created by net/http.(*Transport).dialConn
    /usr/local/go/src/net/http/transport.go:661 +0xcbc
/var/run/docker.sock is up

Here are the full contents of the request logs from the registry for this pull: https://gist.github.com/vincentwoo/92307727cd065788d34f.

In particular, this part jumped out at me:

nginx_1    | 2015/07/27 00:15:42 [error] 9#9: *256 open() "/etc/nginx/html/v1/repositories/coderpad/images" failed (2: No such file or directory), client: 184.172.13.138, server: hub.coderpad.io, request: "GET /v1/repositories/coderpad/images HTTP/1.1", host: "hub.coderpad.io"
nginx_1    | 184.172.13.138 - coderpad [27/Jul/2015:00:15:42 +0000] "GET /v1/repositories/coderpad/images HTTP/1.1" 404 168 "-" "docker/1.7.1 go/go1.4.2 git-commit/786b29d kernel/3.19.0-23-generic os/linux arch/amd64" "-"

The only error in the log here concerns a v1 repository. Why is v1 even in the picture?

About this issue

  • Original URL
  • State: closed
  • Created 9 years ago
  • Comments: 21 (20 by maintainers)

Most upvoted comments

@thaJeztah I think, docker should be more user friendly. Outputting simple “Out of memory” message might save a lot of time for many people.

+2
svetlyak40wt on May 21, 2016
Read more comments on GitHub
← moby: If a remote TCP syslog server is down, docker does not start.
moby: Image tags not working with awslogs log driver →