Etcd: rejected connection from "192.168.3.169:53244" (error "tls: first record does not look like a TLS handshake", ServerName "")

Created on 11 Jul 2018 · 18Comments · Source: etcd-io/etcd

etcd: 3.3.8
OS:CentOS Linux release 7.5.1804 (Core)
Arch: linux/amd64

etcd cluster:

etcd1: 192.168.3.162
etcd2: 192.168.3.168
etcd3: 192.168.3.169

Self-signed certificates：

{
    "CN": "kubernetes",
    "hosts": [
      "127.0.0.1",
            "192.168.3.162",
            "192.168.3.168",
            "192.168.3.169",
            "192.168.3.170",
            "192.168.3.171",
            "192.168.3.172",
            "192.168.3.173",
            "10.0.0.1",
      "kubernetes",
      "kubernetes.default",
      "kubernetes.default.svc",
      "kubernetes.default.svc.cluster",
      "kubernetes.default.svc.cluster.local"
    ],
    "key": {
        "algo": "rsa",
        "size": 2048
    },
    "names": [
        {
            "C": "CN",
            "ST": "ChengDu",
            "L": "ChengDu",
            "O": "k8s",
            "OU": "System"
        }
    ]
}

etcd1.service

[Unit]
Description=Etcd Server
After=network.target

[Service]
Type=simple
WorkingDirectory=/var/lib/etcd/
EnvironmentFile=-/etc/etcd/etcd.conf
ExecStart=/usr/bin/etcd --name etcd1 \
    --initial-advertise-peer-urls https://192.168.3.162:2380 \
    --listen-peer-urls https://192.168.3.162:2380 \
    --listen-client-urls https://192.168.3.162:2379,https://127.0.0.1:2379 \
    --advertise-client-urls https://192.168.3.162:2379 \
    --initial-cluster-token etcd-cluster-1 \
    --initial-cluster etcd1=https://192.168.3.162:2380,etcd2=https://192.168.3.168:2380,etcd3=https://192.168.3.169:2380, \
    --initial-cluster-state new \
    --data-dir=/var/lib/etcd \
    --client-cert-auth \
    --trusted-ca-file=/etc/kubernetes/ssl/ca.pem \
    --cert-file=/etc/kubernetes/ssl/kubernetes.pem \
    --key-file=/etc/kubernetes/ssl/kubernetes-key.pem \
    --peer-client-cert-auth \
    --peer-trusted-ca-file=/etc/kubernetes/ssl/ca.pem \
    --peer-cert-file=/etc/kubernetes/ssl/kubernetes.pem \
    --peer-key-file=/etc/kubernetes/ssl/kubernetes-key.pem

[Install]
WantedBy=multi-user.target

etcd2.service

[Unit]
Description=Etcd Server
After=network.target

[Service]
Type=simple
WorkingDirectory=/var/lib/etcd/
EnvironmentFile=-/etc/etcd/etcd.conf
ExecStart=/usr/bin/etcd --name etcd2 \
    --initial-advertise-peer-urls https://192.168.3.168:2380 \
    --listen-peer-urls https://192.168.3.168:2380 \
    --listen-client-urls https://192.168.3.168:2379,https://127.0.0.1:2379 \
    --advertise-client-urls https://192.168.3.168:2379 \
    --initial-cluster-token etcd-cluster-1 \
    --initial-cluster etcd1=https://192.168.3.162:2380,etcd2=https://192.168.3.168:2380,etcd3=https://192.168.3.169:2380, \
    --initial-cluster-state new \
    --data-dir=/var/lib/etcd \
    --client-cert-auth \
    --trusted-ca-file=/etc/kubernetes/ssl/ca.pem \
    --cert-file=/etc/kubernetes/ssl/kubernetes.pem \
    --key-file=/etc/kubernetes/ssl/kubernetes-key.pem \
    --peer-client-cert-auth \
    --peer-trusted-ca-file=/etc/kubernetes/ssl/ca.pem \
    --peer-cert-file=/etc/kubernetes/ssl/kubernetes.pem \
    --peer-key-file=/etc/kubernetes/ssl/kubernetes-key.pem

[Install]
WantedBy=multi-user.target

etcd3.service

[Unit]
Description=Etcd Server
After=network.target

[Service]
Type=simple
WorkingDirectory=/var/lib/etcd/
EnvironmentFile=-/etc/etcd/etcd.conf
ExecStart=/usr/bin/etcd --name etcd3 \
    --initial-advertise-peer-urls https://192.168.3.169:2380 \
    --listen-peer-urls https://192.168.3.169:2380 \
    --listen-client-urls https://192.168.3.169:2379,https://127.0.0.1:2379 \
    --advertise-client-urls https://192.168.3.169:2379 \
    --initial-cluster-token etcd-cluster-1 \
    --initial-cluster etcd1=https://192.168.3.162:2380,etcd2=https://192.168.3.168:2380,etcd3=https://192.168.3.169:2380, \
    --initial-cluster-state new \
    --data-dir=/var/lib/etcd \
    --client-cert-auth \
    --trusted-ca-file=/etc/kubernetes/ssl/ca.pem \
    --cert-file=/etc/kubernetes/ssl/kubernetes.pem \
    --key-file=/etc/kubernetes/ssl/kubernetes-key.pem \
    --peer-client-cert-auth \
    --peer-trusted-ca-file=/etc/kubernetes/ssl/ca.pem \
    --peer-cert-file=/etc/kubernetes/ssl/kubernetes.pem \
    --peer-key-file=/etc/kubernetes/ssl/kubernetes-key.pem

[Install]
WantedBy=multi-user.target

When I run systemctl start etcd, I get this error(from journalctl -xe):

Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35500" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: publish error: etcdserver: request timed out
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46496" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46500" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35510" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35508" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46504" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46508" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35518" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35516" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46512" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:38 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46516" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35526" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35524" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46520" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46524" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35534" (error "tls: oversized record received with length 21536", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: bab1199d24d460ee is starting a new election at term 925
Jul 11 04:44:39 etcd1 etcd[23500]: bab1199d24d460ee became candidate at term 926
Jul 11 04:44:39 etcd1 etcd[23500]: bab1199d24d460ee received MsgVoteResp from bab1199d24d460ee at term 926
Jul 11 04:44:39 etcd1 etcd[23500]: bab1199d24d460ee [logterm: 510, index: 2621] sent MsgVote request to e3b08f0ab9f3fe8 at term 926
Jul 11 04:44:39 etcd1 etcd[23500]: bab1199d24d460ee [logterm: 510, index: 2621] sent MsgVote request to 341f2c77ffb24eef at term 926
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35536" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35538" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46528" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46532" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35546" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35544" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46536" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46540" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35552" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35554" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46544" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46548" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35562" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35560" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46552" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46556" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46560" (error "tls: oversized record received with length 21536", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35568" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35570" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46564" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46568" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35578" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35576" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46572" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46576" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35584" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35586" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46578" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46584" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35594" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35592" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46588" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46592" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35600" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35602" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46600" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46596" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35608" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35610" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46604" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46608" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35616" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35618" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46612" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46616" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35626" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35624" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46620" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46624" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: bab1199d24d460ee is starting a new election at term 926
Jul 11 04:44:40 etcd1 etcd[23500]: bab1199d24d460ee became candidate at term 927
Jul 11 04:44:40 etcd1 etcd[23500]: bab1199d24d460ee received MsgVoteResp from bab1199d24d460ee at term 927
Jul 11 04:44:40 etcd1 etcd[23500]: bab1199d24d460ee [logterm: 510, index: 2621] sent MsgVote request to e3b08f0ab9f3fe8 at term 927
Jul 11 04:44:40 etcd1 etcd[23500]: bab1199d24d460ee [logterm: 510, index: 2621] sent MsgVote request to 341f2c77ffb24eef at term 927
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35634" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35632" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46628" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46632" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35640" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:40 etcd1 etcd[23500]: rejected connection from "192.168.3.168:35642" (error "tls: first record does not look like a TLS handshake", ServerName "")

arequestion

Source

dangxiaojun

Most helpful comment

@wenjiaswe Did you ever find out what component was trying to connect without TLS? We're running etcd 3.3.11 on-prem (without k8s), with manually generated certs. The etcd cluster seems to be behaving correctly, we can interact with the cluster using etcdctl and it is passing performance tests. However, we are still seeing the "tls: first record does not look like a TLS handshake" error in the logs every 10 seconds (I believe the 10 seconds is due to the transports TLS handshake timeout).

All our peer URL's are https; new members join with https; there is not a single http address in the logs and we are not seeing any certificate errors. The errors only appear after "ready to serve client requests" appears in the logs: as the client/peer listeners only serve requests after this point. I believe the error is caused by a gRPC call to one of these listener endpoints without using TLS, but I am not sure what is making this call.

Do you have any idea what the root cause could be, and if it's critical? Thanks!

tompntn on 10 Jun 2019

👍3

All 18 comments

Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46556" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 04:44:39 etcd1 etcd[23500]: rejected connection from "192.168.3.169:46560" (error "tls: oversized record received with length 21536", ServerName "")

HI @dangxiaojun can you please provide the startup logs for these etcd instances. These errors above indicate that the traffic is not actually HTTPS but HTTP. Perhaps the startup snippet will give us some clues otherwise maybe some kind of proxy issue?.

Also, can you output etcd --version

hexfusion on 11 Jul 2018

[root@etcd1 ~]# etcd --version
etcd Version: 3.3.8
Git SHA: 33245c6b5
Go Version: go1.9.7
Go OS/Arch: linux/amd64

This is startup logs
```
Jul 11 08:13:19 localhost systemd: Started Etcd Server.
Jul 11 08:13:19 localhost systemd: Starting Etcd Server...
Jul 11 08:13:19 localhost journal: Suppressed 96 messages from /system.slice/etcd.service
Jul 11 08:13:19 localhost etcd: etcd Version: 3.3.8
Jul 11 08:13:19 localhost etcd: Git SHA: 33245c6b5
Jul 11 08:13:19 localhost etcd: Go Version: go1.9.7
Jul 11 08:13:19 localhost etcd: Go OS/Arch: linux/amd64
Jul 11 08:13:19 localhost etcd: setting maximum number of CPUs to 1, total number of available CPUs is 1
Jul 11 08:13:19 localhost etcd: found invalid file/dir fixtures under data dir /var/lib/etcd (Ignore this if you are upgrading etcd)
Jul 11 08:13:19 localhost etcd: the server is already initialized as member before, starting as etcd member...
Jul 11 08:13:19 localhost etcd: peerTLS: cert = /etc/kubernetes/ssl/kubernetes.pem, key = /etc/kubernetes/ssl/kubernetes-key.pem, ca = , trusted-ca = /etc/kubernetes/ssl/ca.pem, client-cert-auth = true, crl-file =
Jul 11 08:13:19 localhost etcd: listening for peers on https://192.168.3.162:2380
Jul 11 08:13:19 localhost etcd: listening for client requests on 127.0.0.1:2379
Jul 11 08:13:19 localhost etcd: listening for client requests on 192.168.3.162:2379
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39678" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: name = etcd1
Jul 11 08:13:19 localhost etcd: data dir = /var/lib/etcd
Jul 11 08:13:19 localhost etcd: member dir = /var/lib/etcd/member
Jul 11 08:13:19 localhost etcd: heartbeat = 100ms
Jul 11 08:13:19 localhost etcd: election = 1000ms
Jul 11 08:13:19 localhost etcd: snapshot count = 100000
Jul 11 08:13:19 localhost etcd: advertise client URLs = https://192.168.3.162:2379
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39676" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54700" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54698" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: restarting member bab1199d24d460ee in cluster 31b7399b4ff27c46 at commit index 20240
Jul 11 08:13:19 localhost etcd: bab1199d24d460ee became follower at term 2698
Jul 11 08:13:19 localhost etcd: newRaft bab1199d24d460ee [peers: [], term: 2698, commit: 20240, applied: 0, lastindex: 20240, lastterm: 2334]
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39686" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39684" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: restore compact to 14417
Jul 11 08:13:19 localhost etcd: simple token is not cryptographically signed
Jul 11 08:13:19 localhost etcd: starting server... [version: 3.3.8, cluster version: to_be_decided]
Jul 11 08:13:19 localhost etcd: ClientTLS: cert = /etc/kubernetes/ssl/kubernetes.pem, key = /etc/kubernetes/ssl/kubernetes-key.pem, ca = , trusted-ca = /etc/kubernetes/ssl/ca.pem, client-cert-auth = true, crl-file =
Jul 11 08:13:19 localhost etcd: added member e3b08f0ab9f3fe8 [http://192.168.3.169:2380] to cluster 31b7399b4ff27c46
Jul 11 08:13:19 localhost etcd: starting peer e3b08f0ab9f3fe8...
Jul 11 08:13:19 localhost etcd: started HTTP pipelining with peer e3b08f0ab9f3fe8
Jul 11 08:13:19 localhost etcd: started peer e3b08f0ab9f3fe8
Jul 11 08:13:19 localhost etcd: added peer e3b08f0ab9f3fe8
Jul 11 08:13:19 localhost etcd: added member 341f2c77ffb24eef [http://192.168.3.168:2380] to cluster 31b7399b4ff27c46
Jul 11 08:13:19 localhost etcd: starting peer 341f2c77ffb24eef...
Jul 11 08:13:19 localhost etcd: started HTTP pipelining with peer 341f2c77ffb24eef
Jul 11 08:13:19 localhost etcd: started peer 341f2c77ffb24eef
Jul 11 08:13:19 localhost etcd: added peer 341f2c77ffb24eef
Jul 11 08:13:19 localhost etcd: started streaming with peer e3b08f0ab9f3fe8 (writer)
Jul 11 08:13:19 localhost etcd: started streaming with peer e3b08f0ab9f3fe8 (writer)
Jul 11 08:13:19 localhost etcd: started streaming with peer e3b08f0ab9f3fe8 (stream MsgApp v2 reader)
Jul 11 08:13:19 localhost etcd: started streaming with peer e3b08f0ab9f3fe8 (stream Message reader)
Jul 11 08:13:19 localhost etcd: added member bab1199d24d460ee [http://192.168.3.162:2380] to cluster 31b7399b4ff27c46
Jul 11 08:13:19 localhost etcd: set the initial cluster version to 3.3
Jul 11 08:13:19 localhost etcd: enabled capabilities for version 3.3
Jul 11 08:13:19 localhost etcd: started streaming with peer 341f2c77ffb24eef (writer)
Jul 11 08:13:19 localhost etcd: started streaming with peer 341f2c77ffb24eef (writer)
Jul 11 08:13:19 localhost etcd: started streaming with peer 341f2c77ffb24eef (stream MsgApp v2 reader)
Jul 11 08:13:19 localhost etcd: started streaming with peer 341f2c77ffb24eef (stream Message reader)
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54706" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54708" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39694" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39692" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54716" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54714" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39700" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39702" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54720" (error "tls: oversized record received with length 21536", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54728" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54726" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39710" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39708" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54736" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54734" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39716" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39718" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54744" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.168:54742" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39726" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:19 localhost etcd: rejected connection from "192.168.3.169:39724" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54752" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54750" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39734" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39732" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54760" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54758" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39742" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39740" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54768" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54766" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39750" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39748" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54776" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54774" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39758" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39756" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54784" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54782" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39766" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39764" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54790" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54792" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39772" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39774" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54800" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54798" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39780" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39782" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54808" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54806" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39790" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39788" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54816" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54814" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: bab1199d24d460ee is starting a new election at term 2698
Jul 11 08:13:20 localhost etcd: bab1199d24d460ee became candidate at term 2699
Jul 11 08:13:20 localhost etcd: bab1199d24d460ee received MsgVoteResp from bab1199d24d460ee at term 2699
Jul 11 08:13:20 localhost etcd: bab1199d24d460ee [logterm: 2334, index: 20240] sent MsgVote request to 341f2c77ffb24eef at term 2699
Jul 11 08:13:20 localhost etcd: bab1199d24d460ee [logterm: 2334, index: 20240] sent MsgVote request to e3b08f0ab9f3fe8 at term 2699
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39798" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.169:39796" (error "tls: first record does not look like a TLS handshake", ServerName "")
Jul 11 08:13:20 localhost etcd: rejected connection from "192.168.3.168:54822" (error "tls: first record does not look like a TLS handshake", ServerName "")

dangxiaojun on 11 Jul 2018

I see the added member e3b08f0ab9f3fe8 [http://192.168.3.169:2380] to cluster 31b7399b4ff27c46

But My service file used https

dangxiaojun on 11 Jul 2018

My guess is that the cluster was initially set up wrong. What is the output of below?

ETCDCTL_API=3 etcdctl member list \
--endpoints=https://127.0.0.1:2379 \
--cacert=/etc/kubernetes/ssl/ca.pem \
--cert=/etc/kubernetes/ssl/kubernetes.pem \
--key=/etc/kubernetes/ssl/kubernetes-key.pem

You could try reconfiguring the members to https or start fresh.

https://github.com/coreos/etcd/blob/master/Documentation/op-guide/runtime-configuration.md#cluster-reconfiguration-operations

Possibly related to https://github.com/coreos/etcd/issues/9905 ?

hexfusion on 11 Jul 2018

Hi @dangxiaojun checking in what did you find?

hexfusion on 12 Jul 2018

@dangxiaojun If this is still an issue please feel free to add additional comments.

hexfusion on 13 Jul 2018

No progress, the same configuration, after a few restarts, he can now work normally, using HTTPS, I will continue to observe, thank you for your assistance.

dangxiaojun on 15 Jul 2018

Got similar log when enabling https, after servel restarts the problem still exists.

I refer to this page -> https://github.com/coreos/etcd/blob/master/Documentation/op-guide/runtime-configuration.md#cluster-reconfiguration-operations , update each member's peerURLs from http to https, then restart the cluster again, it works.

yuchengwu on 27 Jul 2018

I've run into the same issue however, the cluster seems to operate just fine - keys are replicated across the cluster.
>etcdctl member list
82aeb37e361d09ed, started, etcd1, https://172.16.253.51:2380, https://172.16.253.51:2379 9d3b38013d4186e6, started, etcd2, https://172.16.253.47:2380, https://172.16.253.47:2379 a2430f07d691d22e, started, etcd3, https://172.16.253.52:2380, https://172.16.253.52:2379

However, issuing
>etcdctl endpoint health --endpoints=172.16.253.51:2380,172.16.253.47:2380,172.16.253.52:2380
results in:
172.16.253.52:2380 is unhealthy: failed to commit proposal: context deadline exceeded 172.16.253.47:2380 is unhealthy: failed to commit proposal: context deadline exceeded 172.16.253.51:2380 is unhealthy: failed to commit proposal: context deadline exceeded Error: unhealthy cluster

and upon execution logs are flooded with
etcdmain: rejected connection from "172.16.253.52:35222" (error "EOF", ServerName "")

v3.2.18 - found only due to prep work for migrating to v3.3.10

piotrgo on 19 Nov 2018

However, issuing
etcdctl endpoint health --endpoints=172.16.253.51:2380,172.16.253.47:2380,172.16.253.52:2380
results in:
172.16.253.52:2380 is unhealthy: failed to commit proposal: context deadline exceeded 172.16.253.47:2380 is unhealthy: failed to commit proposal: context deadline exceeded 172.16.253.51:2380 is unhealthy: failed to commit proposal: context deadline exceeded Error: unhealthy cluster

@piotrgo does changing endpoint port to 2379 resolve the issue?

hexfusion on 19 Nov 2018

Looks like I ran into the same issue when using https instead http when enabling mTLS between etcd server and kube-apiserver in GCE: https://github.com/kubernetes/kubernetes/pull/74690#issuecomment-469083400. My guess is something in still trying to connecting to etcd server using http instead of https, not sure what though. I will keep looking and update if I find the cause.

wenjiaswe on 4 Mar 2019

I ran to the same issue, I have 3 api pods (3 masters) running on centos behing HAProxy, and I am getting :
I0328 13:12:08.436614 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:48960: tls: first record does not look like a TLS handshake
I0328 13:12:08.452375 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:48966: tls: first record does not look like a TLS handshake
I0328 13:12:08.510890 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:48972: tls: first record does not look like a TLS handshake
I0328 13:12:08.511221 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:48978: tls: first record does not look like a TLS handshake
I0328 13:12:08.520668 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:48984: tls: first record does not look like a TLS handshake
I0328 13:12:08.522030 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:48990: tls: first record does not look like a TLS handshake
I0328 13:12:08.529566 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:48996: tls: first record does not look like a TLS handshake
I0328 13:12:08.545460 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49002: tls: first record does not look like a TLS handshake
I0328 13:12:08.550692 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49008: tls: first record does not look like a TLS handshake
I0328 13:12:08.568719 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49014: tls: first record does not look like a TLS handshake
I0328 13:12:08.578375 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49020: tls: first record does not look like a TLS handshake
I0328 13:12:08.590732 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49026: tls: first record does not look like a TLS handshake
I0328 13:12:08.766061 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49032: tls: first record does not look like a TLS handshake
I0328 13:12:09.232213 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49094: tls: first record does not look like a TLS handshake
I0328 13:12:09.244985 1 log.go:172] http: TLS handshake error from HAProxy-PhyiscalIP:49100: tls: first record does not look like a TLS handshake

Ashraf-Hassan on 28 Mar 2019

This means the caller is using HTTP vs HTTPS. If the cluster is using TLS
then HAProxy needs to pass proper TLS credentials to etcd client port.

--
—

hexfusion on 28 Mar 2019

I can not see any link showing how the HAProxy can pass the proper TLS credentials, any guidance please?

Ashraf-Hassan on 4 Apr 2019

Do you have any idea what the root cause could be, and if it's critical? Thanks!

tompntn on 10 Jun 2019

👍3

Jul 05 10:19:19 localhost.localdomain etcd[9275]: etcd Version: 3.3.11
Jul 05 10:19:19 localhost.localdomain etcd[9275]: Git SHA: 2cf9e51
Jul 05 10:19:19 localhost.localdomain etcd[9275]: Go Version: go1.10.3
Jul 05 10:19:19 localhost.localdomain etcd[9275]: Go OS/Arch: linux/amd64
Jul 05 10:19:19 localhost.localdomain etcd[9275]: setting maximum number of CPUs to 4, total number of available CPUs is 4
Jul 05 10:19:19 localhost.localdomain etcd[9275]: the server is already initialized as member before, starting as etcd member...
Jul 05 10:19:19 localhost.localdomain etcd[9275]: cannot listen on TLS for 192.168.79.132:2380: KeyFile and CertFile are not presented
Jul 05 10:19:19 localhost.localdomain systemd[1]: etcd.service: main process exited, code=exited, status=1/FAILURE
Jul 05 10:19:19 localhost.localdomain systemd[1]: Failed to start Etcd Server.

etcd.conf

[member]

ETCD_NAME=etcd0
ETCD_DATA_DIR="/var/lib/etcd/etcd0.etcd"
ETCD_WAL_DIR="/var/lib/etcd/wal"
ETCD_SNAPSHOT_COUNT="100"
ETCD_HEARTBEAT_INTERVAL="100"
ETCD_ELECTION_TIMEOUT="1000"
ETCD_LISTEN_PEER_URLS="https://192.168.79.132:2380"
ETCD_LISTEN_CLIENT_URLS="https://192.168.79.132:2379,https://127.0.0.1:2379"
ETCD_MAX_SNAPSHOTS="5"
ETCD_MAX_WALS="5"

ETCD_CORS=""

what's wrong?

fcddk on 5 Jul 2019

@tompntn sorry for the late response, in my case https://github.com/kubernetes/perf-tests/pull/458 this was the issue, metrics point is trying to access http://127.0.0.1:2379 and can't access. So I use etcd --listen-metrics-urls to redirect metrics to a different port 2382 so who ever is trying to get etcd metrics could use that. Note that both /metrics and /health are sharing the same metrics port if you set --listen-metrics-urls. You may want to check that.

wenjiaswe on 5 Aug 2019

@fcddk your case doesn't look the same the this post. The log says "Jul 05 10:19:19 localhost.localdomain etcd[9275]: cannot listen on TLS for 192.168.79.132:2380: KeyFile and CertFile are not presented" , you might want to follow https://github.com/etcd-io/etcd/blob/master/Documentation/op-guide/security.md and make sure you set up TLS correctly.

wenjiaswe on 5 Aug 2019

Was this page helpful?

0 / 5 - 0 ratings