Unable to start containers at boot time

[elFarto]

I have the plugin installed and working correctly, for manually started containers. However, I have one container set to restart=always, which means it gets started at bootup. When docker attempts this it fails after 60 seconds with the error:

UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=60)

The revelent section from the syslog:

Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="Traceback (most recent call last):"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/flask/app.py\", line 1949, in full_dispatch_request" >
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    rv = self.dispatch_request()" 
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/flask/app.py\", line 1935, in dispatch_request"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    return self.view_functions[rule.endpoint](**req.view_args)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/opt/plugin/net_dhcp/network.py\", line 139, in create_endpoint"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    bridge = net_bridge(network_id)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/opt/plugin/net_dhcp/network.py\", line 58, in net_bridge"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    return ndb.interfaces[client.networks.get(n).attrs['Options'][OPT_BRIDGE]]"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/docker/models/networks.py\", line 180, in get"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    self.client.api.inspect_network(network_id, *args, **kwargs)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/docker/utils/decorators.py\", line 19, in wrapped"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    return f(self, resource_id, *args, **kwargs)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/docker/api/network.py\", line 211, in inspect_network>
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    res = self._get(url, params=params)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/docker/utils/decorators.py\", line 46, in inner"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    return f(self, *args, **kwargs)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/docker/api/client.py\", line 230, in _get"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    return self.get(url, **self._set_request_timeout(kwargs))"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/requests/sessions.py\", line 546, in get"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    return self.request('GET', url, **kwargs)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/requests/sessions.py\", line 533, in request"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    resp = self.send(prep, **send_kwargs)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/requests/sessions.py\", line 646, in send"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    r = adapter.send(request, **kwargs)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="  File \"/usr/local/lib/python3.7/site-packages/requests/adapters.py\", line 529, in send"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="    raise ReadTimeout(e, request=request)"
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="requests.exceptions.ReadTimeout: UnixHTTPConnectionPool(host='localhost', port=None): Read timed out.>
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="<local> - - [20/Dec/2019 08:05:18] \"POST /NetworkDriver.CreateEndpoint HTTP/1.1\" 500 -" plugin=ca4c>
Dec 20 08:05:18 Thor dockerd[1497]: level=warning msg="error locating sandbox id 81ebc1c5a56a16442533b78b3d16f22c61804edd2199bead971c6fe42a68a0f>
Dec 20 08:05:18 Thor dockerd[1497]: level=warning msg="08c4e7ed282f2970be6b95415b33a912bcd72e95aef6037037bf6f60977d2053 cleanup: failed to unmou>
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="08c4e7ed282f2970be6b95415b33a912bcd72e95aef6037037bf6f60977d2053 cleanup: failed to delete >
Dec 20 08:05:18 Thor dockerd[1497]: level=error msg="Failed to start container 08c4e7ed282f2970be6b95415b33a912bcd72e95aef6037037bf6f60977d2053:>
Dec 20 08:05:18 Thor dockerd[1497]: level=info msg="Loading containers: done."
Dec 20 08:05:18 Thor dockerd[1497]: level=info msg="Docker daemon" commit=633a0ea838 graphdriver(s)=overlay2 version=19.03.5
Dec 20 08:05:18 Thor dockerd[1497]: level=info msg="Daemon has completed initialization"
Dec 20 08:05:18 Thor dockerd[1497]: time="2019-12-20T08:05:18.936048081Z" level=info msg="API listen on /run/docker.sock"

This seems to suggest it's trying to access the Docker API before it's been made available. I'm not sure if that's a setup issue on my side or not, I can't see any options to delay starting containers until the API is available.

[denis-bb]

Docker API creation starts after network endpoinds get up. I think network must store its options (bridge name and ipv6 enable option) independently from docker. I try to store options to file and now containers start at boot time without any problems. Also now plugin filling in-file option from the docker option on endpoint creation, so just restart containers after update plugin and everything must work like a charm.

[devplayer0]

Apologies for the late response! I'll look into this with the Go version I'm back to working on.

[blop]

@devplayer0 Hi there! Is there any workaround using a newer version or slightly different configuration?