Friday, 2021-01-08

*** uzumaki has joined #airshipit07:11
*** uzumaki has quit IRC08:20
*** uzumaki has joined #airshipit11:35
*** uzumaki has quit IRC13:18
airship-irc-bot<sb464f> HI Team, I am running into this error when expanding the target cluster to three control nodes. ```baremetalhost.metal3.io/mtn66r05o002 is Current: Resource is current [airshipctl] 2021/01/08 18:29:15 opendev.org/airship/airshipctl@/pkg/events/processor.go:84: Received error when applying errors to kubernetes polling for status failed: etcdserver: request timed out Error events received on channel, errors are: [polling for status20:57
airship-irc-botfailed: etcdserver: request timed out]``` as `airshipctl phase run controlplane-target` waits for resources to be completely up that means waiting for other two control nodes to be deployed. during this process as soon as second  control plane gets deployed etcd start to expand and airshipctl which is querying k8's api gets an error response whoch cause this phase to return with failure status.20:57
airship-irc-bot<sb464f> and this is blocking automation.20:57
airship-irc-bot<sb464f> so any thoughts on this20:59
airship-irc-bot<sb464f> <here> ^^21:02
airship-irc-bot<kk6740> can you verify connection to etcd?21:10
airship-irc-bot<kk6740> that it is fast and stable21:10
airship-irc-bot<sb464f> after the second node joined it was stable21:10
airship-irc-bot<kk6740> what if u run it second time?21:11
airship-irc-bot<kk6740> does it persist ?21:11
airship-irc-bot<sb464f> I didn’t attempt to run it second time.  but if i run it second time will it not bring down the already provisioning node ..?21:12
airship-irc-bot<kk6740> no, it shouldn’t21:12
airship-irc-bot<kk6740> nothing should happen21:12
airship-irc-bot<kk6740> i am not saying that this should be solution21:13
airship-irc-bot<kk6740> just additional information21:13
airship-irc-bot<sb464f> Okay yeah I mean for now I can just put a `|| true`and move fwd but this might be soemthing that need to fixed in airshipctl binary i guess.21:14
airship-irc-bot<kk6740> no need to true for now21:20
airship-irc-bot<kk6740> what happens if u run this second time?21:20
airship-irc-bot<kk6740> because it seems like problem is in etcd, if it is slow21:21
airship-irc-bot<sb464f> looks like apiserver is down21:30
airship-irc-bot<sb464f> api server logs21:31
airship-irc-bot<sb464f> ```PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota. I0108 21:28:38.831695       1 client.go:361] parsed scheme: "endpoint" I0108 21:28:38.831722       1 endpoint.go:68] ccResolverWrapper: sending new addresses to cc: [{https://127.0.0.1:2379  <nil> 0 <nil>}] W0108 21:28:38.831900       1 clientconn.go:1208] grpc:21:31
airship-irc-botaddrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... I0108 21:28:39.827487       1 client.go:361] parsed scheme: "endpoint" I0108 21:28:39.827509       1 endpoint.go:68] ccResolverWrapper: sending new addresses to cc: [{https://127.0.0.1:2379  <nil> 0 <nil>}] W010821:31
airship-irc-bot21:28:39.827796       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:39.832415       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc =21:31
airship-irc-bot"transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:40.828312       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:41.580044       1 clientconn.go:1208] grpc:21:31
airship-irc-botaddrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:42.373060       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp21:31
airship-irc-bot127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:43.649941       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:44.829467       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to21:31
airship-irc-bot{https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:48.371819       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused".21:31
airship-irc-botReconnecting... W0108 21:28:49.589609       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:55.948412       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err21:31
airship-irc-bot:connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... W0108 21:28:57.077012       1 clientconn.go:1208] grpc: addrConn.createTransport failed to connect to {https://127.0.0.1:2379  <nil> 0 <nil>}. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused". Reconnecting... panic: context deadline exceeded21:31
airship-irc-botgoroutine 1 [running]: k8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/registry/customresourcedefinition.NewREST(0xc000922a10, 0x50e7a40, 0xc0002fbb00, 0xc0002fbd28) /workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/registry/customresourcedefinition/etcd.go:56 +0x3e721:31
airship-irc-botk8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/apiserver.completedConfig.New(0xc000e9b100, 0xc000781e88, 0x51a63e0, 0x77457d8, 0x10, 0x0, 0x0) /workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/apiserver/apiserver.go:145 +0x14ef k8s.io/kubernetes/cmd/kube-apiserver/app.createAPIExtensionsServer(0xc000781e80, 0x51a63e0,21:31
airship-irc-bot0x77457d8, 0x0, 0x50e7600, 0xc0004e7700) /workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/cmd/kube-apiserver/app/apiextensions.go:102 +0x59 k8s.io/kubernetes/cmd/kube-apiserver/app.CreateServerChain(0xc0009a7b80, 0xc0001770e0, 0x455c0f4, 0xc, 0xc0008bbc48)21:31
airship-irc-bot/workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/cmd/kube-apiserver/app/server.go:181 +0x2b8 k8s.io/kubernetes/cmd/kube-apiserver/app.Run(0xc0009a7b80, 0xc0001770e0, 0x0, 0x0) /workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/cmd/kube-apiserver/app/server.go:150 +0x10121:31
airship-irc-botk8s.io/kubernetes/cmd/kube-apiserver/app.NewAPIServerCommand.func1(0xc000af9680, 0xc0003c9880, 0x0, 0x1b, 0x0, 0x0) /workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/cmd/kube-apiserver/app/server.go:117 +0x104 k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).execute(0xc000af9680, 0xc00004c1d0, 0x1b, 0x1b, 0xc000af9680, 0xc00004c1d0)21:31
airship-irc-bot/workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:826 +0x460 k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0xc000af9680, 0x16585eff92301cf3, 0x7727600, 0xc000134750)21:31
airship-irc-bot/workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:914 +0x2fb k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).Execute(...) /workspace/anago-v1.18.6-rc.0.48+a9f7208b601483/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:864 main.main()21:31
airship-irc-bot_output/dockerized/go/src/k8s.io/kubernetes/cmd/kube-apiserver/apiserver.go:43 +0xcd```21:31
airship-irc-bot<sb464f> i got response earlier ``` k get bmh NAME           STATUS   PROVISIONING STATUS   CONSUMER                       BMC                                                                 HARDWARE PROFILE   ONLINE   ERROR mtn66r05o001   OK       provisioned           cluster-controlplane-2-2pgbp   redfish+https://32.67.178.70/redfish/v1/Systems/System.Embedded.1   unknown            true      mtn66r05o002   OK       provisioned21:31
airship-irc-botcluster-controlplane-2-wjz87   redfish+https://32.67.178.71/redfish/v1/Systems/System.Embedded.1   unknown            true      mtn66r06o001                                  cluster-controlplane-wvxdf     redfish+https://32.67.178.76/redfish/v1/Systems/System.Embedded.1                      true      root@mtn66r06o001:/home/deployer# k get nodes NAME           STATUS   ROLES    AGE    VERSION mtn66r05o001   Ready    master   28m    v1.18.621:31
airship-irc-botmtn66r05o002   Ready    master   53m    v1.18.6 mtn66r06o001   Ready    master   103m   v1.18.6```21:31
airship-irc-bot<sb464f> this was some time ago.21:31
airship-irc-bot<kk6740> something with etcd21:31
airship-irc-bot<sb464f> yeah21:31
airship-irc-bot<sb464f> ```docker logs a67212aad47f [WARNING] Deprecated '--logger=capnslog' flag is set; use '--logger=zap' flag instead 2021-01-08 21:30:01.526684 I | etcdmain: etcd Version: 3.4.3 2021-01-08 21:30:01.526708 I | etcdmain: Git SHA: 3cf2f69b5 2021-01-08 21:30:01.526712 I | etcdmain: Go Version: go1.12.12 2021-01-08 21:30:01.526716 I | etcdmain: Go OS/Arch: linux/amd64 2021-01-08 21:30:01.526719 I | etcdmain: setting maximum number of CPUs to21:32
airship-irc-bot88, total number of available CPUs is 88 2021-01-08 21:30:01.526775 N | etcdmain: the server is already initialized as member before, starting as etcd member... [WARNING] Deprecated '--logger=capnslog' flag is set; use '--logger=zap' flag instead 2021-01-08 21:30:01.526802 I | embed: peerTLS: cert = /etc/kubernetes/pki/etcd/peer.crt, key = /etc/kubernetes/pki/etcd/peer.key, trusted-ca = /etc/kubernetes/pki/etcd/ca.crt, client-cert-auth = true,21:32
airship-irc-botcrl-file =  2021-01-08 21:30:01.527217 I | embed: name = mtn66r06o001 2021-01-08 21:30:01.527223 I | embed: data dir = /var/lib/etcd 2021-01-08 21:30:01.527226 I | embed: member dir = /var/lib/etcd/member 2021-01-08 21:30:01.527229 I | embed: heartbeat = 100ms 2021-01-08 21:30:01.527233 I | embed: election = 1000ms 2021-01-08 21:30:01.527235 I | embed: snapshot count = 10000 2021-01-08 21:30:01.527241 I | embed: advertise client URLs =21:32
airship-irc-bothttps://32.67.178.17:2379 2021-01-08 21:30:01.527245 I | embed: initial advertise peer URLs = https://32.67.178.17:2380 2021-01-08 21:30:01.527249 I | embed: initial cluster =  2021-01-08 21:30:01.535876 I | etcdserver: recovered store from snapshot at index 80008 2021-01-08 21:30:01.538515 I | mvcc: restore compact to 73593 2021-01-08 21:30:01.636752 I | etcdserver: restarting member eb5edcfccda37839 in cluster f859ca2466f9f6df at commit21:32
airship-irc-botindex 87385 raft2021/01/08 21:30:01 INFO: eb5edcfccda37839 switched to configuration voters=(2179733539865615263 4369031599667737555 16960236225063778361) raft2021/01/08 21:30:01 INFO: eb5edcfccda37839 became follower at term 14 raft2021/01/08 21:30:01 INFO: newRaft eb5edcfccda37839 [peers: [1e3ff81b14b1db9f,3ca1eb177ea6f3d3,eb5edcfccda37839], term: 14, commit: 87385, applied: 80008, lastindex: 87385, lastterm: 14] 2021-01-08 21:30:01.637362 I21:32
airship-irc-bot| etcdserver/api: enabled capabilities for version 3.4 2021-01-08 21:30:01.637372 I | etcdserver/membership: added member 1e3ff81b14b1db9f [https://32.67.178.12:2380] to cluster f859ca2466f9f6df from store 2021-01-08 21:30:01.637377 I | etcdserver/membership: added member 3ca1eb177ea6f3d3 [https://32.67.178.11:2380] to cluster f859ca2466f9f6df from store 2021-01-08 21:30:01.637380 I | etcdserver/membership: added member eb5edcfccda3783921:32
airship-irc-bot[https://32.67.178.17:2380] to cluster f859ca2466f9f6df from store 2021-01-08 21:30:01.637385 I | etcdserver/membership: set the cluster version to 3.4 from store 2021-01-08 21:30:01.637952 I | mvcc: restore compact to 73593 2021-01-08 21:30:01.647364 W | auth: simple token is not cryptographically signed 2021-01-08 21:30:01.648015 I | rafthttp: starting peer 1e3ff81b14b1db9f... 2021-01-08 21:30:01.648035 I | rafthttp: started HTTP pipelining21:32
airship-irc-botwith peer 1e3ff81b14b1db9f 2021-01-08 21:30:01.648364 I | rafthttp: started streaming with peer 1e3ff81b14b1db9f (writer) 2021-01-08 21:30:01.649182 I | rafthttp: started streaming with peer 1e3ff81b14b1db9f (writer) 2021-01-08 21:30:01.650663 I | rafthttp: started peer 1e3ff81b14b1db9f 2021-01-08 21:30:01.650683 I | rafthttp: added peer 1e3ff81b14b1db9f 2021-01-08 21:30:01.650689 I | rafthttp: starting peer 3ca1eb177ea6f3d3... 2021-01-0821:32
airship-irc-bot21:30:01.650716 I | rafthttp: started HTTP pipelining with peer 3ca1eb177ea6f3d3 2021-01-08 21:30:01.650789 I | rafthttp: started streaming with peer 1e3ff81b14b1db9f (stream Message reader) 2021-01-08 21:30:01.650808 I | rafthttp: started streaming with peer 1e3ff81b14b1db9f (stream MsgApp v2 reader) 2021-01-08 21:30:01.651660 I | rafthttp: started streaming with peer 3ca1eb177ea6f3d3 (writer) 2021-01-08 21:30:01.652463 I | rafthttp: started21:32
airship-irc-botstreaming with peer 3ca1eb177ea6f3d3 (writer) 2021-01-08 21:30:01.653946 I | rafthttp: started peer 3ca1eb177ea6f3d3 2021-01-08 21:30:01.653956 I | rafthttp: added peer 3ca1eb177ea6f3d3 2021-01-08 21:30:01.653978 I | etcdserver: starting server... [version: 3.4.3, cluster version: 3.4] 2021-01-08 21:30:01.654075 I | rafthttp: started streaming with peer 3ca1eb177ea6f3d3 (stream Message reader) 2021-01-08 21:30:01.654155 I | rafthttp: started21:32
airship-irc-botstreaming with peer 3ca1eb177ea6f3d3 (stream MsgApp v2 reader) 2021-01-08 21:30:01.657241 I | embed: ClientTLS: cert = /etc/kubernetes/pki/etcd/server.crt, key = /etc/kubernetes/pki/etcd/server.key, trusted-ca = /etc/kubernetes/pki/etcd/ca.crt, client-cert-auth = true, crl-file =  2021-01-08 21:30:01.657301 I | embed: listening for peers on 32.67.178.17:2380 2021-01-08 21:30:01.657371 I | embed: listening for metrics on http://127.0.0.1:238121:32
airship-irc-bot2021-01-08 21:30:01.657748 E | etcdserver: the member has been permanently removed from the cluster 2021-01-08 21:30:01.657759 I | etcdserver: the data-dir used by this member must be removed. 2021-01-08 21:30:01.657776 E | etcdserver: publish error: etcdserver: request cancelled 2021-01-08 21:30:01.657789 I | etcdserver: aborting publish because server is stopped raft2021/01/08 21:30:01 INFO: eb5edcfccda37839 switched to configuration21:32
airship-irc-botvoters=(2179733539865615263 4369031599667737555 15838723492546654337 16960236225063778361) 2021-01-08 21:30:01.671819 I | etcdserver/membership: added member dbce73196ce0b081 [https://32.67.178.14:2380] to cluster f859ca2466f9f6df 2021-01-08 21:30:01.671830 I | rafthttp: starting peer dbce73196ce0b081... 2021-01-08 21:30:01.671880 I | rafthttp: started HTTP pipelining with peer dbce73196ce0b081 2021-01-08 21:30:01.672788 I | rafthttp: started21:32
airship-irc-botstreaming with peer dbce73196ce0b081 (writer) 2021-01-08 21:30:01.673598 I | rafthttp: started streaming with peer dbce73196ce0b081 (writer) 2021-01-08 21:30:01.675155 I | rafthttp: started peer dbce73196ce0b081 2021-01-08 21:30:01.675167 I | rafthttp: added peer dbce73196ce0b081 2021-01-08 21:30:01.675236 I | rafthttp: started streaming with peer dbce73196ce0b081 (stream Message reader) 2021-01-08 21:30:01.675323 I | rafthttp: started21:32
airship-irc-botstreaming with peer dbce73196ce0b081 (stream MsgApp v2 reader) 2021-01-08 21:30:01.676381 I | rafthttp: stopping peer 1e3ff81b14b1db9f... 2021-01-08 21:30:01.676397 I | rafthttp: stopped streaming with peer 1e3ff81b14b1db9f (writer) 2021-01-08 21:30:01.676410 I | rafthttp: stopped streaming with peer 1e3ff81b14b1db9f (writer) 2021-01-08 21:30:01.676428 I | rafthttp: stopped HTTP pipelining with peer 1e3ff81b14b1db9f 2021-01-08 21:30:01.67644921:32
airship-irc-botI | rafthttp: stopped streaming with peer 1e3ff81b14b1db9f (stream MsgApp v2 reader) 2021-01-08 21:30:01.676459 I | rafthttp: stopped streaming with peer 1e3ff81b14b1db9f (stream Message reader) 2021-01-08 21:30:01.676469 I | rafthttp: stopped peer 1e3ff81b14b1db9f 2021-01-08 21:30:01.676475 I | rafthttp: stopping peer 3ca1eb177ea6f3d3... 2021-01-08 21:30:01.676485 I | rafthttp: stopped streaming with peer 3ca1eb177ea6f3d3 (writer) 2021-01-0821:32
airship-irc-bot21:30:01.676496 I | rafthttp: stopped streaming with peer 3ca1eb177ea6f3d3 (writer) 2021-01-08 21:30:01.676512 I | rafthttp: stopped HTTP pipelining with peer 3ca1eb177ea6f3d3 2021-01-08 21:30:01.676523 I | rafthttp: stopped streaming with peer 3ca1eb177ea6f3d3 (stream MsgApp v2 reader) 2021-01-08 21:30:01.676533 I | rafthttp: stopped streaming with peer 3ca1eb177ea6f3d3 (stream Message reader) 2021-01-08 21:30:01.676541 I | rafthttp: stopped21:32
airship-irc-botpeer 3ca1eb177ea6f3d3 2021-01-08 21:30:01.676544 I | rafthttp: stopping peer dbce73196ce0b081... 2021-01-08 21:30:01.676551 I | rafthttp: stopped streaming with peer dbce73196ce0b081 (writer) 2021-01-08 21:30:01.676558 I | rafthttp: stopped streaming with peer dbce73196ce0b081 (writer) 2021-01-08 21:30:01.676569 I | rafthttp: stopped HTTP pipelining with peer dbce73196ce0b081 2021-01-08 21:30:01.676579 I | rafthttp: stopped streaming with peer21:32
airship-irc-bot<kk6740> may there be that u have old etcd somewhere else sitting?21:34
airship-irc-bot<kk6740> and they fail to form a cluster?21:34
airship-irc-bot<sb464f> old etcd was cleaned as the three control nodes are in the cluster earlier.21:34
airship-irc-bot<kk6740> and you are scaling etcd from 1 node to 3?21:36
airship-irc-bot<sb464f> I am not, cluster api does that right..?21:38
airship-irc-bot<kk6740> yea21:38
airship-irc-bot<sb464f> frist target node and when second joins second etcd was scaled and waits for third node to join.21:39
airship-irc-bot<kk6740> so that is where the problem is probably21:39
airship-irc-bot<kk6740> can u debug logs on the sencond etcd as well?21:40
airship-irc-bot<kk6740> and check how it is launched21:40
airship-irc-bot<sb464f> the other etcd pods seems to be running fine.21:42

Generated by irclog2html.py 2.17.2 by Marius Gedminas - find it at https://mg.pov.lt/irclog2html/!