After installing the latest stable version of docker-ce (5:18.09.0~3-0~raspbian-stretch as of the time of writing), Docker would take ages to start after a reboot. Commands would even time out waiting for it.
/var/log/daemon.log shows a gap of almost 4 minutes between the attempt to start the Docker Application Container Engine and the first log line from dockerd.
Jul 5 10:10:37 RPi systemd[1]: Starting Docker Application Container Engine...
Jul 5 10:14:07 RPi dockerd[683]: time="2019-07-05T10:14:07.808215720+02:00" level=info msg="parsed scheme: \"unix\"" module=grpc
After installing a later version of docker-ce from the test branch in attempt to remedy this, I got an interesting message while the issue persisted:
Jul 5 10:42:18 RPi systemd[1]: Starting Docker Application Container Engine...
Jul 5 10:43:30 RPi dockerd[720]: crypto/rand: blocked for 60 seconds waiting to read random data from the kernel
Jul 5 10:47:27 RPi dockerd[720]: time="2019-07-05T10:47:27.245479521+02:00" level=info msg="Starting up"
Turns out it doesn’t have enough random entropy to start. We can help the Pi generate this by running haveged. A quick apt-get install haveged and a reboot later, the logs look much better, and Docker starts immediately.
# apt-get install haveged
...
# reboot
The result, after downgrading to the stable version of Docker again:
Jul 5 11:08:02 RPi systemd[1]: Starting Docker Application Container Engine...
Jul 5 11:08:06 RPi dockerd[707]: time="2019-07-05T11:08:06.793516408+02:00" level=info msg="parsed scheme: \"unix\"" module=grpc
From 4 minutes to 4 seconds is a rather significant improvement, I think 🙂
2 Comments
Thank you for this. This was the most exotic issue I’ve ever seen. And the crypto/rand error was only visible for me after hours of messing around. Anyways. Thanks for shgaring this.
To echo J: the most exotic issue I’ve ever seen. Apparent when running docker -v shortly after a reboot. Any way many thanks – saving me hours waiting for a reboot to complete.