Cannot assign requested address after switching from 3.1.0 to 3.2.0

[lucastheisen]

After switching, i see this message repeated constantly in my log:

etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: dial tcp [::]:2379: connect: cannot assign requested address"; Reconnecting to {[::]:2379 <nil>}

The easiest way to reproduce is using docker:

Version 3.1.0

$HostIP = "127.0.0.1"
docker run --rm --name "etcd" `
    -p 4001:4001 -p 2380:2380 -p 2379:2379 `
    "quay.io/coreos/etcd:v3.1.0" `
    "/usr/local/bin/etcd" `
    -name "etcd0" `
    -advertise-client-urls "http://${HostIP}:2379,http://${HostIP}:4001" `
    -listen-client-urls "http://0.0.0.0:2379,http://0.0.0.0:4001" `
    -initial-advertise-peer-urls "http://${HostIP}:2380" `
    -listen-peer-urls "http://0.0.0.0:2380" `
    -initial-cluster-token "etcd-cluster-1" `
    -initial-cluster "etcd0=http://${HostIP}:2380" `
    -initial-cluster-state "new"

Which results in:

2017-06-21 21:59:16.618163 I | etcdmain: etcd Version: 3.1.0
2017-06-21 21:59:16.618243 I | etcdmain: Git SHA: 8ba2897
2017-06-21 21:59:16.618257 I | etcdmain: Go Version: go1.7.4
2017-06-21 21:59:16.618262 I | etcdmain: Go OS/Arch: linux/amd64
2017-06-21 21:59:16.618270 I | etcdmain: setting maximum number of CPUs to 2, total number of available CPUs is 2
2017-06-21 21:59:16.618278 W | etcdmain: no data-dir provided, using default data-dir ./etcd0.etcd
2017-06-21 21:59:16.618397 I | embed: listening for peers on http://0.0.0.0:2380
2017-06-21 21:59:16.618462 I | embed: listening for client requests on 0.0.0.0:2379
2017-06-21 21:59:16.618520 I | embed: listening for client requests on 0.0.0.0:4001
2017-06-21 21:59:16.637051 I | etcdserver: name = etcd0
2017-06-21 21:59:16.637155 I | etcdserver: data dir = etcd0.etcd
2017-06-21 21:59:16.637182 I | etcdserver: member dir = etcd0.etcd/member
2017-06-21 21:59:16.637203 I | etcdserver: heartbeat = 100ms
2017-06-21 21:59:16.637265 I | etcdserver: election = 1000ms
2017-06-21 21:59:16.637305 I | etcdserver: snapshot count = 10000
2017-06-21 21:59:16.637713 I | etcdserver: advertise client URLs = http://127.0.0.1:2379,http://127.0.0.1:4001
2017-06-21 21:59:16.637775 I | etcdserver: initial advertise peer URLs = http://127.0.0.1:2380
2017-06-21 21:59:16.637814 I | etcdserver: initial cluster = etcd0=http://127.0.0.1:2380
2017-06-21 21:59:16.660800 I | etcdserver: starting member bf9071f4639c75cc in cluster 7bdc11851051b492
2017-06-21 21:59:16.660865 I | raft: bf9071f4639c75cc became follower at term 0
2017-06-21 21:59:16.660880 I | raft: newRaft bf9071f4639c75cc [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
2017-06-21 21:59:16.660886 I | raft: bf9071f4639c75cc became follower at term 1
2017-06-21 21:59:16.708332 I | etcdserver: starting server... [version: 3.1.0, cluster version: to_be_decided]
2017-06-21 21:59:16.710355 I | etcdserver/membership: added member bf9071f4639c75cc [http://127.0.0.1:2380] to cluster 7bdc11851051b492
2017-06-21 21:59:16.761392 I | raft: bf9071f4639c75cc is starting a new election at term 1
2017-06-21 21:59:16.761496 I | raft: bf9071f4639c75cc became candidate at term 2
2017-06-21 21:59:16.761515 I | raft: bf9071f4639c75cc received MsgVoteResp from bf9071f4639c75cc at term 2
2017-06-21 21:59:16.761532 I | raft: bf9071f4639c75cc became leader at term 2
2017-06-21 21:59:16.761692 I | raft: raft.node: bf9071f4639c75cc elected leader bf9071f4639c75cc at term 2
2017-06-21 21:59:16.762462 I | etcdserver: setting up the initial cluster version to 3.1
2017-06-21 21:59:16.767016 N | etcdserver/membership: set the initial cluster version to 3.1
2017-06-21 21:59:16.767131 I | etcdserver/api: enabled capabilities for version 3.1
2017-06-21 21:59:16.767334 I | embed: ready to serve client requests
2017-06-21 21:59:16.767657 I | embed: ready to serve client requests
2017-06-21 21:59:16.768219 N | embed: serving insecure client requests on [::]:2379, this is strongly discouraged!
2017-06-21 21:59:16.768467 N | embed: serving insecure client requests on [::]:4001, this is strongly discouraged!
2017-06-21 21:59:16.768576 I | etcdserver: published {Name:etcd0 ClientURLs:[http://127.0.0.1:2379 http://127.0.0.1:4001]} to cluster 7bdc11851051b492

Version 3.2.0

$HostIP = "127.0.0.1"
docker run --rm --name "etcd" `
    -p 4001:4001 -p 2380:2380 -p 2379:2379 `
    "quay.io/coreos/etcd:v3.2.0" `
    "/usr/local/bin/etcd" `
    -name "etcd0" `
    -advertise-client-urls "http://${HostIP}:2379,http://${HostIP}:4001" `
    -listen-client-urls "http://0.0.0.0:2379,http://0.0.0.0:4001" `
    -initial-advertise-peer-urls "http://${HostIP}:2380" `
    -listen-peer-urls "http://0.0.0.0:2380" `
    -initial-cluster-token "etcd-cluster-1" `
    -initial-cluster "etcd0=http://${HostIP}:2380" `
    -initial-cluster-state "new"

Which results in:

2017-06-21 21:57:12.758794 I | etcdmain: etcd Version: 3.2.0
2017-06-21 21:57:12.758970 I | etcdmain: Git SHA: 66722b1
2017-06-21 21:57:12.758989 I | etcdmain: Go Version: go1.8.3
2017-06-21 21:57:12.759002 I | etcdmain: Go OS/Arch: linux/amd64
2017-06-21 21:57:12.759016 I | etcdmain: setting maximum number of CPUs to 2, total number of available CPUs is 2
2017-06-21 21:57:12.759060 W | etcdmain: no data-dir provided, using default data-dir ./etcd0.etcd
2017-06-21 21:57:12.759741 I | embed: listening for peers on http://0.0.0.0:2380
2017-06-21 21:57:12.760984 I | embed: listening for client requests on 0.0.0.0:2379
2017-06-21 21:57:12.761069 I | embed: listening for client requests on 0.0.0.0:4001
2017-06-21 21:57:12.776016 I | etcdserver: name = etcd0
2017-06-21 21:57:12.776088 I | etcdserver: data dir = etcd0.etcd
2017-06-21 21:57:12.776115 I | etcdserver: member dir = etcd0.etcd/member
2017-06-21 21:57:12.776876 I | etcdserver: heartbeat = 100ms
2017-06-21 21:57:12.776955 I | etcdserver: election = 1000ms
2017-06-21 21:57:12.776974 I | etcdserver: snapshot count = 100000
2017-06-21 21:57:12.777040 I | etcdserver: advertise client URLs = http://127.0.0.1:2379,http://127.0.0.1:4001
2017-06-21 21:57:12.777060 I | etcdserver: initial advertise peer URLs = http://127.0.0.1:2380
2017-06-21 21:57:12.777084 I | etcdserver: initial cluster = etcd0=http://127.0.0.1:2380
2017-06-21 21:57:12.799344 I | etcdserver: starting member bf9071f4639c75cc in cluster 7bdc11851051b492
2017-06-21 21:57:12.799449 I | raft: bf9071f4639c75cc became follower at term 0
2017-06-21 21:57:12.799695 I | raft: newRaft bf9071f4639c75cc [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
2017-06-21 21:57:12.799735 I | raft: bf9071f4639c75cc became follower at term 1
2017-06-21 21:57:12.825283 W | auth: simple token is not cryptographically signed
2017-06-21 21:57:12.838134 I | etcdserver: starting server... [version: 3.2.0, cluster version: to_be_decided]
2017-06-21 21:57:12.839914 I | etcdserver/membership: added member bf9071f4639c75cc [http://127.0.0.1:2380] to cluster 7bdc11851051b492
2017-06-21 21:57:13.700562 I | raft: bf9071f4639c75cc is starting a new election at term 1
2017-06-21 21:57:13.700674 I | raft: bf9071f4639c75cc became candidate at term 2
2017-06-21 21:57:13.700727 I | raft: bf9071f4639c75cc received MsgVoteResp from bf9071f4639c75cc at term 2
2017-06-21 21:57:13.700761 I | raft: bf9071f4639c75cc became leader at term 2
2017-06-21 21:57:13.700788 I | raft: raft.node: bf9071f4639c75cc elected leader bf9071f4639c75cc at term 2
2017-06-21 21:57:13.701072 I | etcdserver: setting up the initial cluster version to 3.2
2017-06-21 21:57:13.706215 N | etcdserver/membership: set the initial cluster version to 3.2
2017-06-21 21:57:13.706341 I | etcdserver: published {Name:etcd0 ClientURLs:[http://127.0.0.1:2379 http://127.0.0.1:4001]} to cluster 7bdc11851051b492
2017-06-21 21:57:13.706396 I | etcdserver/api: enabled capabilities for version 3.2
2017-06-21 21:57:13.706441 I | embed: ready to serve client requests
2017-06-21 21:57:13.707279 N | embed: serving insecure client requests on [::]:2379, this is strongly discouraged!
2017-06-21 21:57:13.707669 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: dial tcp [::]:2379: connect: cannot assign requested address"; Reconnecting to {[::]:2379 <nil>}
2017-06-21 21:57:13.707848 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: dial tcp [::]:2379: connect: cannot assign requested address"; Reconnecting to {[::]:2379 <nil>}
2017-06-21 21:57:13.708019 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: dial tcp [::]:2379: connect: cannot assign requested address"; Reconnecting to {[::]:2379 <nil>}
2017-06-21 21:57:13.708195 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: dial tcp [::]:2379: connect: cannot assign requested address"; Reconnecting to {[::]:2379 <nil>}
...

And the last 3 lines just keep repeating. I can still use the etcd instance, but the logs get filled with that error message.

[rollcat]

Seeing the same thing

[ehudkaldor]

me too

[heyitsanthony]

Can reproduce with --sysctl net.ipv6.conf.all.disable_ipv6=1. Probably related to the listener address giving IPv6 [::] even if passed IPv4 0.0.0.0