Greetings,
I’ve been debugging this for a few days without much avail. I’ve got a NanoPC T4 https://www.friendlyarm.com/index.php?route=product/product&product_id=225 which i’ve picked up to run docker builds for our Arm64 CI service.
The running theory is that something is held up waiting on a response its not getting, or somethings getting lost in the stack during a docker push. It doesn’t seem to matter which image, if it has a slightly large layer (talking 100mb or > which isn’t uncommon with FROM ubuntu based images, but this isn’t that large)
$ docker info [16/1279]
Client:
Debug Mode: false
Server:
Containers: 0
Running: 0
Paused: 0
Stopped: 0
Images: 24
Server Version: 19.03.5
Storage Driver: overlay2
Backing Filesystem: extfs
Supports d_type: true
Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
Volume: local
Network: bridge host ipvlan macvlan null overlay
Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: b34a5c8af56e510852c35414db4c1f4fa6172339
runc version: 3e425f80a8c931f88e6d94a8c831b9d5aa481657
init version: fec3683
Security Options:
seccomp
Profile: default
Kernel Version: 5.4.8-rockchip64
Operating System: Ubuntu 18.04.3 LTS
OSType: linux
Architecture: aarch64
CPUs: 6
Total Memory: 3.777GiB
Name: nanopct4
ID: FR4B:FTU3:D5OO:UECD:5XEU:RESM:AZ3A:D7NB:QT6L:PXN7:XDEE:A5ZO
Docker Root Dir: /var/lib/docker
Debug Mode: true
File Descriptors: 27
Goroutines: 51
System Time: 2020-01-17T16:35:06.096291204Z
EventsListeners: 0
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: false
Here’s the debug log from the server when pushing:
$ journalctl -fu docker
-- Logs begin at Fri 2020-01-17 15:27:14 UTC. --
Jan 17 16:08:06 nanopct4 dockerd[11120]: time="2020-01-17T16:08:06.763366406Z" level=debug msg="Calling HEAD /_ping"
Jan 17 16:08:06 nanopct4 dockerd[11120]: time="2020-01-17T16:08:06.765591214Z" level=debug msg="Calling GET /v1.40/info"
Jan 17 16:08:06 nanopct4 dockerd[11120]: time="2020-01-17T16:08:06.800459553Z" level=debug msg="Calling POST /v1.40/images/vaporio/foundation/push?tag=ubuntu-18.04-arm64"
Jan 17 16:08:06 nanopct4 dockerd[11120]: time="2020-01-17T16:08:06.800851257Z" level=debug msg="Trying to push docker.io/vaporio/foundation to https://registry-1.docker.io v2"
Jan 17 16:08:06 nanopct4 dockerd[11120]: time="2020-01-17T16:08:06.988402092Z" level=debug msg="Pushing repository: vaporio/foundation:ubuntu-18.04-arm64"
Jan 17 16:08:06 nanopct4 dockerd[11120]: time="2020-01-17T16:08:06.990432944Z" level=debug msg="Checking for presence of layer sha256:0bbd4f741fb16c67683fe7194410666ea49eab6cb470a6b751d0c86e8f08813b (sha256:becd4379202995fec4d9caa15a1bb3d3c38611a09e6ee6b2e0dc0eb5de891be1) in docker.io/vaporio/foundation"
Jan 17 16:08:07 nanopct4 dockerd[11120]: time="2020-01-17T16:08:07.806994629Z" level=debug msg="Checking for presence of layer sha256:99ddc8d25836aaf02bb0478bf941c516788036999a54d6bd99d70bbc9a36dd74 (sha256:968a7955c09232bd9a3d8c45ea6add82bab148823d784219e87f6e00e17a022b) in docker.io/vaporio/foundation"
Jan 17 16:08:08 nanopct4 dockerd[11120]: time="2020-01-17T16:08:08.328077249Z" level=debug msg="Checking for presence of layer sha256:d70b1f8551e429a9a49b296aa1e46fe5d8ab57593205f80b70d42da85bb1db56 (sha256:335c90dd12613626a3d70909e4456bf1e40596110e798c670cb803d0987b1e9b) in docker.io/vaporio/foundation"
Jan 17 16:08:08 nanopct4 dockerd[11120]: time="2020-01-17T16:08:08.881901108Z" level=debug msg="Pushing layer: sha256:ceda0264c8b600030b94030bdb685690e292d4ef71836c93240aca5cdbcc9b7a"
Jan 17 16:08:09 nanopct4 dockerd[11120]: time="2020-01-17T16:08:09.152881629Z" level=debug msg="Assembling tar data for 3f870d24488aa976217c10d584a9b70f26d3c16ed19cd3499a057167abfb860e"
Jan 17 16:14:57 nanopct4 dockerd[11120]: time="2020-01-17T16:14:57.572564615Z" level=error msg="Upload failed, retrying: received unexpected HTTP status: 504 Gateway Time-out"
Jan 17 16:15:02 nanopct4 dockerd[11120]: time="2020-01-17T16:15:02.573136807Z" level=debug msg="Pushing layer: sha256:ceda0264c8b600030b94030bdb685690e292d4ef71836c93240aca5cdbcc9b7a"
Jan 17 16:15:03 nanopct4 dockerd[11120]: time="2020-01-17T16:15:03.108649069Z" level=debug msg="Assembling tar data for 3f870d24488aa976217c10d584a9b70f26d3c16ed19cd3499a057167abfb860e"
What’s interesting is I see the 504 gateway timeout, but the end-user output doesn’t reflect that, its just a timeout / retry
+ docker push vaporio/foundation:ubuntu-18.04-arm64
The push refers to repository [docker.io/vaporio/foundation]
0bbd4f741fb1: Preparing
99ddc8d25836: Preparing
d70b1f8551e4: Preparing
ceda0264c8b6: Preparing
99ddc8d25836: Waiting
d70b1f8551e4: Waiting
ceda0264c8b6: Waiting
0bbd4f741fb1: Layer already exists
99ddc8d25836: Layer already exists
d70b1f8551e4: Layer already exists
ceda0264c8b6: Retrying in 5 seconds
ceda0264c8b6: Retrying in 4 seconds
ceda0264c8b6: Retrying in 3 seconds
ceda0264c8b6: Retrying in 2 seconds
ceda0264c8b6: Retrying in 1 second
inspecting the layers built:
$ docker history vaporio/foundation:ubuntu-18.04-arm64
IMAGE CREATED CREATED BY SIZE COMMENT
0ad49bb3ba79 15 minutes ago /bin/sh -c #(nop) LABEL build.source=master 0B
c83315bee7fc 15 minutes ago /bin/sh -c #(nop) LABEL build.number=1428 0B
376934f88303 36 minutes ago /bin/sh -c #(nop) CMD ["/bin/bash"] 0B
f62ec6e57b50 36 minutes ago |2 ARCH=arm64 VERSION=bionic /bin/sh -c apt-… 9.83MB
6e58d619f6c2 36 minutes ago |2 ARCH=arm64 VERSION=bionic /bin/sh -c mkdi… 7B
2e381e8284e4 36 minutes ago |2 ARCH=arm64 VERSION=bionic /bin/sh -c set … 745B
7a7baf6d6481 36 minutes ago /bin/sh -c #(nop) ADD file:d5f7aaeac134f4bf7… 56.7MB
ffdbef2b8afa 38 minutes ago /bin/sh -c #(nop) ARG ARCH=amd64 0B
41e437b722f0 38 minutes ago /bin/sh -c #(nop) ARG VERSION 0B
Netstat listing of connection(s)
$ netstat
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 670424 nanopct4:52034 ec2-34-199-40-84.:https CLOSE_WAIT -- (failed push)
tcp 0 1517504 nanopct4:54442 ec2-54-210-105-17:https ESTABLISHED -- (active attempt)
tcp 0 164 nanopct4:ssh 10.1.0.198:34866 ESTABLISHED
Active UNIX domain sockets (w/o servers)
If there are any ideas of what else to tune or prod for details, i’m game. This has caused me to really scratch my chin for several days and i’m curious if there’s a simple explanation.
Note: this is on the 5.4 kernel series of Armbian Bionic
https://www.armbian.com/nanopc-t4/
I’ve also tried the 4.4 stable series of bionic and a 4.4 series of Debian Buster. All exhibit the same broken behavior. The only differences i’m aware of: are kernels, and potentially the usage of networkmanager on armbian (but i somehow doubt this is the culprit)
) and I push from there… and yup it’s working.