2017-05-31-etcdadm-reconfigure.log

May 30 21:35:58 ip-10-100-2-111.ec2.internal systemd[1]: Starting etcdadm reconfigure runner...
May 30 21:35:58 ip-10-100-2-111.ec2.internal systemctl[7975]: active
May 30 21:35:58 ip-10-100-2-111.ec2.internal etcdadm[7992]: declare -x ETCDCTL_CACERT="/etc/ssl/certs/ca.pem"
May 30 21:35:58 ip-10-100-2-111.ec2.internal etcdadm[7992]: declare -x ETCDCTL_CA_FILE="/etc/ssl/certs/ca.pem"
May 30 21:35:58 ip-10-100-2-111.ec2.internal etcdadm[7992]: declare -x ETCDCTL_CERT="/etc/ssl/certs/etcd-client.pem"
May 30 21:35:58 ip-10-100-2-111.ec2.internal etcdadm[7992]: declare -x ETCDCTL_CERT_FILE="/etc/ssl/certs/etcd-client.pem"
May 30 21:35:58 ip-10-100-2-111.ec2.internal etcdadm[7992]: declare -x ETCDCTL_KEY="/etc/ssl/certs/etcd-client-key.pem"
May 30 21:35:58 ip-10-100-2-111.ec2.internal etcdadm[7992]: declare -x ETCDCTL_KEY_FILE="/etc/ssl/certs/etcd-client-key.pem"
May 30 21:35:59 ip-10-100-2-111.ec2.internal sudo[8009]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/[ -w /var/run/coreos/etcdadm ]
May 30 21:35:59 ip-10-100-2-111.ec2.internal sudo[8009]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:35:59 ip-10-100-2-111.ec2.internal sudo[8054]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/[ -w /var/run/coreos/etcdadm/snapshots ]
May 30 21:35:59 ip-10-100-2-111.ec2.internal sudo[8054]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:35:59 ip-10-100-2-111.ec2.internal sudo[8064]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/[ -w /var/lib/etcd2 ]
May 30 21:35:59 ip-10-100-2-111.ec2.internal sudo[8064]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:05 ip-10-100-2-111.ec2.internal etcdadm[7992]: [208294.843870] etcd[5]: https://ec2-12-34-123-321.compute-1.amazonaws.com:2379 is healthy: successfully committed proposal: took = 109.066801ms
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: [208304.230508] etcd[5]: https://ec2-56-78-111-12.compute-1.amazonaws.com:2379 is healthy: successfully committed proposal: took = 163.029873ms
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_reconfigure: observing cluster state: quorum=2 healthy=2
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_is_unstarted: connecting to https://ec2-56-78-111-12.compute-1.amazonaws.com:2379
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: 1434d2d34c5fe93d: name=etcd1 peerURLs=https://ec2-34-56-123-321.compute-1.amazonaws.com:2380 clientURLs=https://ec2-34-56-123-321.compute-1.amazonaws.com:2379 isLeader=false
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: fffabc123badcafe: name=etcd2 peerURLs=https://ec2-56-78-111-12.compute-1.amazonaws.com:2380 clientURLs=https://ec2-56-78-111-12.compute-1.amazonaws.com:2379 isLeader=false
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: 123abc456badbeef: name=etcd0 peerURLs=https://ec2-12-34-123-321.compute-1.amazonaws.com:2380 clientURLs=https://ec2-12-34-123-321.compute-1.amazonaws.com:2379 isLeader=true
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_reconfigure: this member is failing longer than limit
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: cleaning data dir of etcd1
May 30 21:36:15 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: data dir /var/lib/etcd2 exists. finding files to remove
May 30 21:36:15 ip-10-100-2-111.ec2.internal sudo[8616]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/bash -c cd /var/lib/etcd2 && find *
May 30 21:36:15 ip-10-100-2-111.ec2.internal sudo[8616]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:16 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/lost+found
May 30 21:36:16 ip-10-100-2-111.ec2.internal sudo[8645]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/lost+found
May 30 21:36:16 ip-10-100-2-111.ec2.internal sudo[8645]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:16 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member
May 30 21:36:16 ip-10-100-2-111.ec2.internal sudo[8671]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member
May 30 21:36:16 ip-10-100-2-111.ec2.internal sudo[8671]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:17 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/snap
May 30 21:36:17 ip-10-100-2-111.ec2.internal sudo[8692]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/snap
May 30 21:36:17 ip-10-100-2-111.ec2.internal sudo[8692]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:18 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/snap/db
May 30 21:36:18 ip-10-100-2-111.ec2.internal sudo[8713]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/snap/db
May 30 21:36:18 ip-10-100-2-111.ec2.internal sudo[8713]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:18 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/snap/0000000000003993-000000000020ab3b.snap
May 30 21:36:18 ip-10-100-2-111.ec2.internal sudo[8746]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/snap/0000000000003993-000000000020ab3b.snap
May 30 21:36:18 ip-10-100-2-111.ec2.internal sudo[8746]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:19 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/snap/0000000000003993-000000000020d805.snap
May 30 21:36:19 ip-10-100-2-111.ec2.internal sudo[8765]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/snap/0000000000003993-000000000020d805.snap
May 30 21:36:19 ip-10-100-2-111.ec2.internal sudo[8765]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:19 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/snap/0000000000003993-000000000021001c.snap
May 30 21:36:19 ip-10-100-2-111.ec2.internal sudo[8777]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/snap/0000000000003993-000000000021001c.snap
May 30 21:36:19 ip-10-100-2-111.ec2.internal sudo[8777]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:20 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/snap/0000000000003993-0000000000205ce6.snap
May 30 21:36:20 ip-10-100-2-111.ec2.internal sudo[8814]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/snap/0000000000003993-0000000000205ce6.snap
May 30 21:36:20 ip-10-100-2-111.ec2.internal sudo[8814]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:21 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/snap/0000000000003993-00000000002083fc.snap
May 30 21:36:21 ip-10-100-2-111.ec2.internal sudo[8839]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/snap/0000000000003993-00000000002083fc.snap
May 30 21:36:21 ip-10-100-2-111.ec2.internal sudo[8839]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:21 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/wal
May 30 21:36:21 ip-10-100-2-111.ec2.internal sudo[8853]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/wal
May 30 21:36:21 ip-10-100-2-111.ec2.internal sudo[8853]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 30 21:36:21 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: removing /var/lib/etcd2/member/wal/0000000000000018-00000000001c56a0.wal
May 30 21:36:22 ip-10-100-2-111.ec2.internal sudo[8881]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /var/lib/etcd2/member/wal/0000000000000018-00000000001c56a0.wal
May 30 21:36:25 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_clean_data_dir: leaving directory /var/lib/etcd2
May 30 21:36:25 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_replace_failed: connecting to https://ec2-56-78-111-12.compute-1.amazonaws.com:2379
May 30 21:36:25 ip-10-100-2-111.ec2.internal etcdadm[7992]: 1434d2d34c5fe93d: name=etcd1 peerURLs=https://ec2-34-56-123-321.compute-1.amazonaws.com:2380 clientURLs=https://ec2-34-56-123-321.compute-1.amazonaws.com:2379 isLeader=false
May 30 21:36:25 ip-10-100-2-111.ec2.internal etcdadm[7992]: fffabc123badcafe: name=etcd2 peerURLs=https://ec2-56-78-111-12.compute-1.amazonaws.com:2380 clientURLs=https://ec2-56-78-111-12.compute-1.amazonaws.com:2379 isLeader=false
May 30 21:36:25 ip-10-100-2-111.ec2.internal etcdadm[7992]: 123abc456badbeef: name=etcd0 peerURLs=https://ec2-12-34-123-321.compute-1.amazonaws.com:2380 clientURLs=https://ec2-12-34-123-321.compute-1.amazonaws.com:2379 isLeader=true
May 30 21:36:26 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_replace_failed: removing member 1434d2d34c5fe93d
May 30 21:36:26 ip-10-100-2-111.ec2.internal etcdadm[7992]: Removed member 1434d2d34c5fe93d from cluster
May 30 21:36:27 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_replace_failed: adding member 1434d2d34c5fe93d
May 30 21:36:27 ip-10-100-2-111.ec2.internal etcdadm[7992]: Added member named etcd1 with ID a9683b938d606d79 to cluster
May 30 21:36:27 ip-10-100-2-111.ec2.internal etcdadm[7992]: ETCD_NAME="etcd1"
May 30 21:36:27 ip-10-100-2-111.ec2.internal etcdadm[7992]: ETCD_INITIAL_CLUSTER="etcd2=https://ec2-56-78-111-12.compute-1.amazonaws.com:2380,etcd1=https://ec2-34-56-123-321.compute-1.amazonaws.com:2380,etcd0=https://ec2-56-78-111-12.compute-1.amazonaws.com:2380
May 30 21:36:27 ip-10-100-2-111.ec2.internal etcdadm[7992]: ETCD_INITIAL_CLUSTER_STATE="existing"
May 30 21:36:27 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: member_set_initial_cluster_state: setting initial cluster state to: existing
May 30 21:36:27 ip-10-100-2-111.ec2.internal etcdadm[7992]: /opt/bin/etcdadm: info: _systemctl_daemon_reload: running `systemctl daemon-reload` to reload etcd-member.service
May 30 21:36:29 ip-10-100-2-111.ec2.internal systemd[1]: Started etcdadm reconfigure runner.
May 31 20:45:44 ip-10-100-2-111.ec2.internal systemd[1]: Stopped etcdadm reconfigure runner.

[... SNIP ...]
[... Now many repeated patterns of the following: ...]
[... SNIP ...]

May 31 22:17:23 ip-10-100-2-111.ec2.internal systemd[1]: Stopped etcdadm reconfigure runner.
May 31 22:17:33 ip-10-100-2-111.ec2.internal systemd[1]: Starting etcdadm reconfigure runner...
May 31 22:17:33 ip-10-100-2-111.ec2.internal systemctl[28720]: active
May 31 22:17:33 ip-10-100-2-111.ec2.internal etcdadm[28736]: declare -x ETCDCTL_CACERT="/etc/ssl/certs/ca.pem"
May 31 22:17:33 ip-10-100-2-111.ec2.internal etcdadm[28736]: declare -x ETCDCTL_CA_FILE="/etc/ssl/certs/ca.pem"
May 31 22:17:33 ip-10-100-2-111.ec2.internal etcdadm[28736]: declare -x ETCDCTL_CERT="/etc/ssl/certs/etcd-client.pem"
May 31 22:17:33 ip-10-100-2-111.ec2.internal etcdadm[28736]: declare -x ETCDCTL_CERT_FILE="/etc/ssl/certs/etcd-client.pem"
May 31 22:17:33 ip-10-100-2-111.ec2.internal etcdadm[28736]: declare -x ETCDCTL_KEY="/etc/ssl/certs/etcd-client-key.pem"
May 31 22:17:33 ip-10-100-2-111.ec2.internal etcdadm[28736]: declare -x ETCDCTL_KEY_FILE="/etc/ssl/certs/etcd-client-key.pem"
May 31 22:17:33 ip-10-100-2-111.ec2.internal sudo[28742]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/[ -w /var/run/coreos/etcdadm ]
May 31 22:17:33 ip-10-100-2-111.ec2.internal sudo[28742]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 31 22:17:34 ip-10-100-2-111.ec2.internal sudo[28772]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/[ -w /var/run/coreos/etcdadm/snapshots ]
May 31 22:17:34 ip-10-100-2-111.ec2.internal sudo[28772]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 31 22:17:34 ip-10-100-2-111.ec2.internal sudo[28814]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/[ -w /var/lib/etcd2 ]
May 31 22:17:34 ip-10-100-2-111.ec2.internal sudo[28814]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 31 22:17:36 ip-10-100-2-111.ec2.internal etcdadm[28736]: [ 5440.370388] etcd[5]: https://ec2-12-34-123-321.compute-1.amazonaws.com:2379 is healthy: successfully committed proposal: took = 9.630827ms
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: [ 5446.230462] etcd[5]: https://ec2-56-78-111-12.compute-1.amazonaws.com:2379 is healthy: successfully committed proposal: took = 2.468089ms
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_reconfigure: observing cluster state: quorum=2 healthy=2
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_is_unstarted: connecting to https://ec2-56-78-111-12.compute-1.amazonaws.com:2379
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: fffabc123badcafe: name=etcd2 peerURLs=https://ec2-56-78-111-12.compute-1.amazonaws.com:2380 clientURLs=https://ec2-56-78-111-12.compute-1.amazonaws.com:2379 isLeader=true
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: a9683b938d606d79[unstarted]: peerURLs=https://ec2-34-56-123-321.compute-1.amazonaws.com:2380
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: 123abc456badbeef: name=etcd0 peerURLs=https://ec2-12-34-123-321.compute-1.amazonaws.com:2380 clientURLs=https://ec2-12-34-123-321.compute-1.amazonaws.com:2379 isLeader=false
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_is_unstarted: unstarted peer for this member(etcd1) is found
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: cat: /var/run/coreos/etcdadm/status: No such file or directory
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_reconfigure: cluster is already healthy but still in bootstrap process after the disaster recovery. searching for a etcd snapshot to recover this member
May 31 22:17:42 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_remote_snapshot_exists: checking existence of s3://test-etcd-fail-example/kube-aws/clusters/etcd-fail/instances/9f6c6e20-400f-11e7-8527-500c32cd4462/etcd-snapshots/snapshot.db
May 31 22:17:43 ip-10-100-2-111.ec2.internal etcdadm[28736]: An error occurred (AccessDenied) when calling the ListObjects operation: Access Denied
May 31 22:17:44 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_remote_snapshot_exists: s3://test-etcd-fail-example/kube-aws/clusters/etcd-fail/instances/9f6c6e20-400f-11e7-8527-500c32cd4462/etcd-snapshots/snapshot.db does not exist
May 31 22:17:44 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_bootstrap: remote snapshot for etcd1 does not exist. skipped downloading
May 31 22:17:44 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_local_snapshot_exists: checking existence of file /var/run/coreos/etcdadm/snapshots/etcd1.db
May 31 22:17:44 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_bootstrap: backup not found. starting brand new etcd1...
May 31 22:17:44 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: member_set_initial_cluster_state: setting initial cluster state to: new
May 31 22:17:44 ip-10-100-2-111.ec2.internal etcdadm[28736]: /opt/bin/etcdadm: info: _systemctl_daemon_reload: running `systemctl daemon-reload` to reload etcd-member.service
May 31 22:17:44 ip-10-100-2-111.ec2.internal systemd[1]: Started etcdadm reconfigure runner.