Sensuctl configure: unable to authenticate with error: Unauthorized

[Capt-Tom]

I checked the existing topics for messages similar to this:

Sensuctl configure prompting error : Error: unable to authenticate with error: Unauthorized

I just install sensugo 5.19.1 on centos7. When i configure it it show follwing error. [root@dev-box-c7 ~]# sensuctl configure ? Sensu Backend URL: http://127.0.0.1:8080 ? Username: admin ? Password: ********* ? Namespace: default ? Preferred output format: tabular WARN[0011] Using Basic Auth in HTTP mode is not secure, use HTTPS component=cli-client Error: unable to authenticate with error: Unauthorized

Not able to configure SSL authentication

@palourde that may be a result of my adding ``` to the code to make it a bit more readable. @balajik515 can you paste the config in again, but ensure that you’ve surrounded the example with ``` ?

Neither were much help. Receiving this error when attempting to configure sensuctl for configuration of the backend.

user@host:~$ /usr/bin/sensuctl configure --non-interactive --username admin --password REDACTED --url https://127.0.0.1:8080

Error: unable to authenticate with error: Unauthorized

Running the configure from within the container spit back SSL errors I have corrected. It now returns the same error as outside the container.

root@8b89c1e7e159:/opt/sensu# /usr/bin/sensuctl configure --non-interactive --username admin --password REDACTED --url https://127.0.0.1:8080

Error: unable to authenticate with error: Unauthorized

Logs indicate the backend is being initialized correctly. Variables that are necessary for initialization are present in the shell as they were in testing environments that have successfully been configured.

user@host:~$ sudo docker exec -ti 8b89c1e7e159 /bin/bash
root@8b89c1e7e159:/opt/sensu# printenv
SENSU_BACKEND_CLUSTER_ADMIN_PASSWORD=<correct_password>
HOSTNAME=8b89c1e7e159
SENSU_BACKEND_CLUSTER_ADMIN_USERNAME=admin

sudo docker logs 8b89c1e7e159
Waiting for backend to become available...
{"component":"etcd","level":"info","msg":"listening for peers on ","pkg":"embed","time":"2020-08-12T18:28:41Z"}
...
Running initialization...
{"component":"etcd","level":"info","msg":"http: TLS handshake error from 127.0.0.1:38770: EOF\n","pkg":"","time":"2020-08-12T18:28:43Z"}
{"component":"backend.seeds","level":"info","msg":"store already initialized","time":"2020-08-12T18:28:43Z"}

OpenSSL is able to verify certificates being presented on 8080 during handshake.

user@host:~$ openssl s_client -connect localhost:8080
CONNECTED(00000003)
[cert chain information...]
---
No client certificate CA names sent
Peer signing digest: SHA256
Peer signature type: RSA-PSS
Server Temp Key: X25519, 253 bits
---
SSL handshake has read 1903 bytes and written 347 bytes
Verification: OK
---
New, TLSv1.3, Cipher is TLS_AES_128_GCM_SHA256
Server public key is 2048 bit
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
Early data was not sent
Verify return code: 0 (ok)
---
Post-Handshake New Session Ticket arrived:
...
Start Time: 1597334616
Timeout   : 7200 (sec)
Verify return code: 0 (ok)
Extended master secret: no
Max Early Data: 0

From within the container this fails with error code 21. I would expect this to succeed but not surprised a shell within the container may not have what it needs to verify certs using the container orchestration host store.

Verify return code: 21 (unable to verify the first certificate)

Logs from container at same time sensuctl configure is run:

{"component":"authentication","error":"key admin not found","level":"debug","msg":"could not authenticate with provider \"basic\"","time":"2020-08-13T15:49:37Z"}
{"component":"apid.routers","error":"unauthorized","level":"error","msg":"invalid username and/or password","time":"2020-08-13T15:49:37Z","user":"admin"}

I believe my SSL configuration issues have been solved as I can verify a handshake to port 8080.

• Does the presence of a TLS handshake error from etcd mean the process within the container is unable to verify the certificate etcd is running with?
• Why is the first initialization being run stating that the store as already been initialized?
• Does the authentication error message mean there is no user with the name “admin?”

Anything to point me towards new problems to investigate would be appreciated. Much obliged for your help.

[jspaleta]

Just to clarify… you are doing this all from inside the official docker container? including the sensuctl configure?

[Capt-Tom]

When I first wrote this I was not, I was running a self hosted image rebuilt to on some different image layers, which originally solved some problems with initialization I had with a prior version. I saw the release of major version 6 and hoped its changes to initialization/entrypoint would solve this.

I reconfigured everything to pull from the official build. It’s worth noting that all of my configuration works as documented/intended within vagrant virtual images and does not now that this is running wild on an ec2 instance. Both my in-house image and the sensu/sensu:latest image function in dev and fail the same way within AWS. I’m going to start looking into how that could cause this but here’s some similar behavior from the sensu/sensu image.

user@host:~$ sudo !!
sudo docker images
REPOSITORY                   TAG                 IMAGE ID            CREATED             SIZE
sensu/sensu                  latest              a86adb906547        3 days ago          114MB

user@host-00:~$ sudo docker container ls --no-trunc
CONTAINER ID                                                       IMAGE                COMMAND                                                                                                                                                                                                                                                                                                                CREATED             STATUS              PORTS                                                                     NAMES
bcb9e916f6cbd94654e7d11f6939ea3b1ce9a34ba3ef8b8c82fa6dd667ec34de   sensu/sensu:latest   "sensu-backend start --state-dir /var/lib/sensu/sensu-backend --log-level debug --insecure-skip-tls-verify false --cert-file /var/lib/sensu/sensu-backend/dev.sensu.domain.com.crt --key-file /var/lib/sensu/sensu-backend/dev.sensu.domain.com.key --trusted-ca-file /var/lib/sensu/sensu-backend/ca.pem"   13 minutes ago      Up 13 minutes       0.0.0.0:3000->3000/tcp, 2379-2380/tcp, 0.0.0.0:8080-8081->8080-8081/tcp   docker.sensu-backend.service

$ sudo !!
sudo docker logs bcb9e916f6cb
== waiting for bcb9e916f6cb:2379 to become available before running backend-init...
{"component":"etcd","level":"info","msg":"listening for peers on ","pkg":"embed","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"http://[::]:2380","pkg":"embed","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"listening for client requests on ","pkg":"embed","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"[::]:2379","pkg":"embed","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"name = default","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"data dir = /var/lib/sensu/sensu-backend/etcd/data","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"member dir = /var/lib/sensu/sensu-backend/etcd/data/member","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"dedicated WAL dir = /var/lib/sensu/sensu-backend/etcd/wal","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"heartbeat = 100ms","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"election = 1000ms","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"snapshot count = 100000","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"advertise client URLs = http://bcb9e916f6cb:2379","pkg":"etcdserver","time":"2020-08-14T01:22:01Z"}
{"component":"etcd","level":"info","msg":"restarting member 8927110dc66458af in cluster 3b0efc7b379f89be at commit index 48616","pkg":"etcdserver","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became follower at term 11","pkg":"raft","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"info","msg":"newRaft 8927110dc66458af [peers: [], term: 11, commit: 48616, applied: 0, lastindex: 48616, lastterm: 11]","pkg":"raft","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"warning","msg":"simple token is not cryptographically signed","pkg":"auth","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"info","msg":"restore compact to 38735","pkg":"mvcc","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"info","msg":"starting server... [version: 3.3.22, cluster version: to_be_decided]","pkg":"etcdserver","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"info","msg":"added member 8927110dc66458af [http://127.0.0.1:2380] to cluster 3b0efc7b379f89be","pkg":"etcdserver/membership","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"warning","msg":"set the initial cluster version to 3.3","pkg":"etcdserver/membership","time":"2020-08-14T01:22:02Z"}
{"component":"etcd","level":"info","msg":"enabled capabilities for version 3.3","pkg":"etcdserver/api","time":"2020-08-14T01:22:02Z"}
== waiting for bcb9e916f6cb:2379 to become available before running backend-init...
== running backend init...
{"component":"etcd","level":"info","msg":"8927110dc66458af is starting a new election at term 11","pkg":"raft","time":"2020-08-14T01:22:03Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became candidate at term 12","pkg":"raft","time":"2020-08-14T01:22:03Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af received MsgVoteResp from 8927110dc66458af at term 12","pkg":"raft","time":"2020-08-14T01:22:03Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became leader at term 12","pkg":"raft","time":"2020-08-14T01:22:03Z"}
{"component":"etcd","level":"info","msg":"raft.node: 8927110dc66458af elected leader 8927110dc66458af at term 12","pkg":"raft","time":"2020-08-14T01:22:03Z"}
{"component":"etcd","level":"info","msg":"published {Name:default ClientURLs:[http://bcb9e916f6cb:2379]} to cluster 3b0efc7b379f89be","pkg":"etcdserver","time":"2020-08-14T01:22:03Z"}
{"component":"sensu-etcd","level":"info","msg":"Etcd ready to serve client connections","time":"2020-08-14T01:22:03Z"}
{"component":"etcd","level":"info","msg":"ready to serve client requests","pkg":"embed","time":"2020-08-14T01:22:03Z"}
{"component":"etcd","level":"warning","msg":"serving insecure client requests on [::]:2379, this is strongly discouraged!","pkg":"embed","time":"2020-08-14T01:22:03Z"}
{"component":"backend.seeds","level":"info","msg":"store already initialized","time":"2020-08-14T01:22:03Z"}
{"component":"backend","level":"debug","msg":"Registering backend...","time":"2020-08-14T01:22:03Z"}

{"component":"authentication","error":"key admin not found","level":"debug","msg":"could not authenticate with provider \"basic\"","time":"2020-08-13T15:49:37Z"}
{"component":"apid.routers","error":"unauthorized","level":"error","msg":"invalid username and/or password","time":"2020-08-13T15:49:37Z","user":"admin"}

[Capt-Tom]

I removed the SSL configuration entirely from the host I’ve been deploying this on and the behavior persists. I also tried running the sensu-rhel image with no change.

ubuntu@sensu-00:/var/log$ sudo docker container ls
CONTAINER ID        IMAGE                COMMAND                  CREATED             STATUS              PORTS                                                                     NAMES
5e86d313924c        sensu/sensu:latest   "sensu-backend start…"   2 seconds ago       Up 1 second         0.0.0.0:3000->3000/tcp, 2379-2380/tcp, 0.0.0.0:8080-8081->8080-8081/tcp   docker.sensu-backend.service
ubuntu@sensu-00:/var/log$ sudo docker logs 5e86d313924c
== waiting for 5e86d313924c:2379 to become available before running backend-init...
{"component":"etcd","level":"info","msg":"listening for peers on ","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"http://[::]:2380","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"listening for client requests on ","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"[::]:2379","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"name = default","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"data dir = /var/lib/sensu/sensu-backend/etcd/data","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"member dir = /var/lib/sensu/sensu-backend/etcd/data/member","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"dedicated WAL dir = /var/lib/sensu/sensu-backend/etcd/wal","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"heartbeat = 100ms","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"election = 1000ms","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"snapshot count = 100000","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"advertise client URLs = http://5e86d313924c:2379","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"restarting member 8927110dc66458af in cluster 3b0efc7b379f89be at commit index 64488","pkg":"etcdserver","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became follower at term 15","pkg":"raft","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"newRaft 8927110dc66458af [peers: [], term: 15, commit: 64488, applied: 0, lastindex: 64488, lastterm: 15]","pkg":"raft","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"warning","msg":"simple token is not cryptographically signed","pkg":"auth","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"restore compact to 51353","pkg":"mvcc","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"starting server... [version: 3.3.22, cluster version: to_be_decided]","pkg":"etcdserver","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"added member 8927110dc66458af [http://127.0.0.1:2380] to cluster 3b0efc7b379f89be","pkg":"etcdserver/membership","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"warning","msg":"set the initial cluster version to 3.3","pkg":"etcdserver/membership","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"enabled capabilities for version 3.3","pkg":"etcdserver/api","time":"2020-08-14T17:32:07Z"}
== waiting for 5e86d313924c:2379 to become available before running backend-init...
== running backend init...
{"component":"etcd","level":"info","msg":"8927110dc66458af is starting a new election at term 15","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became candidate at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af received MsgVoteResp from 8927110dc66458af at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became leader at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"raft.node: 8927110dc66458af elected leader 8927110dc66458af at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"published {Name:default ClientURLs:[http://5e86d313924c:2379]} to cluster 3b0efc7b379f89be","pkg":"etcdserver","time":"2020-08-14T17:32:08Z"}
{"component":"sensu-etcd","level":"info","msg":"Etcd ready to serve client connections","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"ready to serve client requests","pkg":"embed","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"warning","msg":"serving insecure client requests on [::]:2379, this is strongly discouraged!","pkg":"embed","time":"2020-08-14T17:32:08Z"}
{"component":"backend","level":"debug","msg":"Registering backend...","time":"2020-08-14T17:32:08Z"}
{"component":"backend","level":"debug","msg":"Done registering backend.","time":"2020-08-14T17:32:08Z"}
{"component":"backend","entity":{"entity_class":"backend","system":{"hostname":"5e86d313924c","os":"linux","platform":"alpine","platform_family":"alpine","platform_version":"3.8.5","network":{"interfaces":[{"name":"lo","addresses":["127.0.0.1/8"]},{"name":"eth0","mac":"02:42:ac:11:00:02","addresses":["172.17.0.2/16"]}]},"arch":"amd64","libc_type":"musl","vm_system":"docker","vm_role":"guest","cloud_provider":"","processes":null},"subscriptions":null,"last_seen":0,"deregister":false,"deregistration":{},"metadata":{"name":"5e86d313924c"},"sensu_agent_version":""},"level":"info","msg":"backend entity information","time":"2020-08-14T17:32:08Z"}
{"cache":"/var/cache/sensu/sensu-backend","component":"asset-manager","level":"debug","msg":"initializing cache directory","time":"2020-08-14T17:32:08Z"}
{"component":"backend.seeds","level":"info","msg":"store already initialized","time":"2020-08-14T17:32:08Z"}
{"cache":"/var/cache/sensu/sensu-backend","component":"asset-manager","level":"debug","msg":"done initializing cache directory","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/entity_configs/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/api/enterprise/federation/v1/etcd-replicators/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"eventd","level":"info","msg":"no event log file specified, event logging is disabled","time":"2020-08-14T17:32:08Z"}
{"component":"licensing","level":"info","msg":"starting the license watcher","time":"2020-08-14T17:32:08Z"}
{"component":"licensing","level":"info","msg":"no enterprise license found","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/api/enterprise/licensing/v2/license","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store-providers","level":"info","msg":"starting the event store providers watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/api/enterprise/store/v1/provider/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store-providers","level":"info","msg":"no event store provider found","time":"2020-08-14T17:32:08Z"}
{"component":"agentd","level":"info","msg":"starting agentd on address: [::]:8081","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/checks/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"apid","level":"info","msg":"starting apid on address: [::]:8080","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","level":"info","msg":"tessen is opted in, enabling tessen.. thank you so much for your support 💚","opt-out":false,"time":"2020-08-14T17:32:08Z"}
{"component":"metricsd","level":"info","msg":"starting metricsd","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/tessen","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","error":"key /sensu.io/api/enterprise/licensing/v2/license not found","level":"debug","msg":"unable to retrieve license","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","level":"debug","metric_name":"backend_count","metric_value":1,"msg":"collected a metric for tessen","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","level":"debug","msg":"added a backend to tessen","time":"2020-08-14T17:32:08Z","values":["61e8f878-b00e-4f83-ad49-248c363ffb62"]}
{"component":"tessend","key":"61e8f878-b00e-4f83-ad49-248c363ffb62","level":"debug","msg":"added a key to the ring","time":"2020-08-14T17:32:08Z"}
{"component":"metricsd","level":"info","msg":"metricsd running","time":"2020-08-14T17:32:10Z"}
{"component":"auth-providers","level":"info","msg":"starting the authentication providers watcher","time":"2020-08-14T17:32:10Z"}
{"component":"auth-providers","level":"info","msg":"no authentication provider found","time":"2020-08-14T17:32:10Z"}
{"component":"store","key":"/sensu.io/api/enterprise/authentication/v2/authproviders/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:10Z"}
{"component":"secrets-providers","level":"info","msg":"starting the secrets providers watcher","time":"2020-08-14T17:32:10Z"}
{"component":"secrets-providers","level":"info","msg":"enabled secrets provider \"env\"","time":"2020-08-14T17:32:10Z"}
{"component":"store","key":"/sensu.io/api/enterprise/secrets/v1/providers/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:10Z"}
{"component":"web","level":"info","msg":"starting webd on address: [::]:3000","time":"2020-08-14T17:32:10Z"}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Silenced","time":"2020-08-14T17:32:13Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:13Z"}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Namespace","time":"2020-08-14T17:32:13Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:13Z"}
{"component":"tessend","level":"debug","metric_name":"event_count","metric_value":0,"msg":"collected a metric for tessen","time":"2020-08-14T17:32:13Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"event_metrics","time":"2020-08-14T17:32:13Z"}
ubuntu@sensu-00:/var/log$ sudo /usr/bin/sensuctl configure --non-interactive --username admin --password REDACTED --url http://127.0.0.1:8080

Error: unable to authenticate with error: Unauthorized

ubuntu@sensu-00:/var/log$ sudo docker logs 5e86d313924c
== waiting for 5e86d313924c:2379 to become available before running backend-init...
{"component":"etcd","level":"info","msg":"listening for peers on ","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"http://[::]:2380","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"listening for client requests on ","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"[::]:2379","pkg":"embed","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"name = default","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"data dir = /var/lib/sensu/sensu-backend/etcd/data","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"member dir = /var/lib/sensu/sensu-backend/etcd/data/member","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"dedicated WAL dir = /var/lib/sensu/sensu-backend/etcd/wal","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"heartbeat = 100ms","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"election = 1000ms","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"snapshot count = 100000","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"advertise client URLs = http://5e86d313924c:2379","pkg":"etcdserver","time":"2020-08-14T17:32:06Z"}
{"component":"etcd","level":"info","msg":"restarting member 8927110dc66458af in cluster 3b0efc7b379f89be at commit index 64488","pkg":"etcdserver","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became follower at term 15","pkg":"raft","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"newRaft 8927110dc66458af [peers: [], term: 15, commit: 64488, applied: 0, lastindex: 64488, lastterm: 15]","pkg":"raft","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"warning","msg":"simple token is not cryptographically signed","pkg":"auth","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"restore compact to 51353","pkg":"mvcc","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"starting server... [version: 3.3.22, cluster version: to_be_decided]","pkg":"etcdserver","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"added member 8927110dc66458af [http://127.0.0.1:2380] to cluster 3b0efc7b379f89be","pkg":"etcdserver/membership","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"warning","msg":"set the initial cluster version to 3.3","pkg":"etcdserver/membership","time":"2020-08-14T17:32:07Z"}
{"component":"etcd","level":"info","msg":"enabled capabilities for version 3.3","pkg":"etcdserver/api","time":"2020-08-14T17:32:07Z"}
== waiting for 5e86d313924c:2379 to become available before running backend-init...
== running backend init...
{"component":"etcd","level":"info","msg":"8927110dc66458af is starting a new election at term 15","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became candidate at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af received MsgVoteResp from 8927110dc66458af at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"8927110dc66458af became leader at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"raft.node: 8927110dc66458af elected leader 8927110dc66458af at term 16","pkg":"raft","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"published {Name:default ClientURLs:[http://5e86d313924c:2379]} to cluster 3b0efc7b379f89be","pkg":"etcdserver","time":"2020-08-14T17:32:08Z"}
{"component":"sensu-etcd","level":"info","msg":"Etcd ready to serve client connections","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"info","msg":"ready to serve client requests","pkg":"embed","time":"2020-08-14T17:32:08Z"}
{"component":"etcd","level":"warning","msg":"serving insecure client requests on [::]:2379, this is strongly discouraged!","pkg":"embed","time":"2020-08-14T17:32:08Z"}
{"component":"backend","level":"debug","msg":"Registering backend...","time":"2020-08-14T17:32:08Z"}
{"component":"backend","level":"debug","msg":"Done registering backend.","time":"2020-08-14T17:32:08Z"}
{"component":"backend","entity":{"entity_class":"backend","system":{"hostname":"5e86d313924c","os":"linux","platform":"alpine","platform_family":"alpine","platform_version":"3.8.5","network":{"interfaces":[{"name":"lo","addresses":["127.0.0.1/8"]},{"name":"eth0","mac":"02:42:ac:11:00:02","addresses":["172.17.0.2/16"]}]},"arch":"amd64","libc_type":"musl","vm_system":"docker","vm_role":"guest","cloud_provider":"","processes":null},"subscriptions":null,"last_seen":0,"deregister":false,"deregistration":{},"metadata":{"name":"5e86d313924c"},"sensu_agent_version":""},"level":"info","msg":"backend entity information","time":"2020-08-14T17:32:08Z"}
{"cache":"/var/cache/sensu/sensu-backend","component":"asset-manager","level":"debug","msg":"initializing cache directory","time":"2020-08-14T17:32:08Z"}
{"component":"backend.seeds","level":"info","msg":"store already initialized","time":"2020-08-14T17:32:08Z"}
{"cache":"/var/cache/sensu/sensu-backend","component":"asset-manager","level":"debug","msg":"done initializing cache directory","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/entity_configs/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/api/enterprise/federation/v1/etcd-replicators/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"eventd","level":"info","msg":"no event log file specified, event logging is disabled","time":"2020-08-14T17:32:08Z"}
{"component":"licensing","level":"info","msg":"starting the license watcher","time":"2020-08-14T17:32:08Z"}
{"component":"licensing","level":"info","msg":"no enterprise license found","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/api/enterprise/licensing/v2/license","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store-providers","level":"info","msg":"starting the event store providers watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/api/enterprise/store/v1/provider/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"store-providers","level":"info","msg":"no event store provider found","time":"2020-08-14T17:32:08Z"}
{"component":"agentd","level":"info","msg":"starting agentd on address: [::]:8081","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/checks/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"apid","level":"info","msg":"starting apid on address: [::]:8080","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","level":"info","msg":"tessen is opted in, enabling tessen.. thank you so much for your support 💚","opt-out":false,"time":"2020-08-14T17:32:08Z"}
{"component":"metricsd","level":"info","msg":"starting metricsd","time":"2020-08-14T17:32:08Z"}
{"component":"store","key":"/sensu.io/tessen","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","error":"key /sensu.io/api/enterprise/licensing/v2/license not found","level":"debug","msg":"unable to retrieve license","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","level":"debug","metric_name":"backend_count","metric_value":1,"msg":"collected a metric for tessen","time":"2020-08-14T17:32:08Z"}
{"component":"tessend","level":"debug","msg":"added a backend to tessen","time":"2020-08-14T17:32:08Z","values":["61e8f878-b00e-4f83-ad49-248c363ffb62"]}
{"component":"tessend","key":"61e8f878-b00e-4f83-ad49-248c363ffb62","level":"debug","msg":"added a key to the ring","time":"2020-08-14T17:32:08Z"}
{"component":"metricsd","level":"info","msg":"metricsd running","time":"2020-08-14T17:32:10Z"}
{"component":"auth-providers","level":"info","msg":"starting the authentication providers watcher","time":"2020-08-14T17:32:10Z"}
{"component":"auth-providers","level":"info","msg":"no authentication provider found","time":"2020-08-14T17:32:10Z"}
{"component":"store","key":"/sensu.io/api/enterprise/authentication/v2/authproviders/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:10Z"}
{"component":"secrets-providers","level":"info","msg":"starting the secrets providers watcher","time":"2020-08-14T17:32:10Z"}
{"component":"secrets-providers","level":"info","msg":"enabled secrets provider \"env\"","time":"2020-08-14T17:32:10Z"}
{"component":"store","key":"/sensu.io/api/enterprise/secrets/v1/providers/","level":"debug","msg":"starting a watcher","time":"2020-08-14T17:32:10Z"}
{"component":"web","level":"info","msg":"starting webd on address: [::]:3000","time":"2020-08-14T17:32:10Z"}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Silenced","time":"2020-08-14T17:32:13Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:13Z"}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Namespace","time":"2020-08-14T17:32:13Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:13Z"}
{"component":"tessend","level":"debug","metric_name":"event_count","metric_value":0,"msg":"collected a metric for tessen","time":"2020-08-14T17:32:13Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"event_metrics","time":"2020-08-14T17:32:13Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"entity_metrics","time":"2020-08-14T17:32:14Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"cluster_metrics","time":"2020-08-14T17:32:15Z"}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Silenced","time":"2020-08-14T17:32:18Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:18Z"}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Namespace","time":"2020-08-14T17:32:18Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:18Z"}
{"component":"tessend","level":"debug","metric_name":"filter_count","metric_value":0,"msg":"collected a metric for tessen","time":"2020-08-14T17:32:18Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"event_metrics","time":"2020-08-14T17:32:18Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"entity_metrics","time":"2020-08-14T17:32:19Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"cluster_metrics","time":"2020-08-14T17:32:20Z"}
{"component":"authentication","error":"key admin not found","level":"debug","msg":"could not authenticate with provider \"basic\"","time":"2020-08-14T17:32:21Z"}
{"component":"apid.routers","error":"unauthorized","level":"error","msg":"invalid username and/or password","time":"2020-08-14T17:32:21Z","user":"admin"}
{"component":"apid","duration":"0.653ms","level":"info","method":"GET","msg":"request completed","path":"/auth","size":13,"status":401,"time":"2020-08-14T17:32:21Z","user":""}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Silenced","time":"2020-08-14T17:32:23Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:23Z"}
{"cache_version":"v1","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v2.Namespace","time":"2020-08-14T17:32:23Z"}
{"cache_version":"v2","component":"cache","level":"debug","msg":"rebuilding the cache for resource type *v3.EntityConfig","time":"2020-08-14T17:32:23Z"}
{"component":"tessend","level":"debug","metric_name":"mutator_count","metric_value":0,"msg":"collected a metric for tessen","time":"2020-08-14T17:32:23Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"event_metrics","time":"2020-08-14T17:32:23Z"}
{"backend_id":"b8a122d3-35bf-41cd-ab9d-bf2624c355ba","component":"metricsd","level":"debug","msg":"metricsd heartbeat","name":"entity_metrics","time":"2020-08-14T17:32:24Z"}

user@host-00:/var/log$ curl http://127.0.0.1:8080/health
{"Alarms":null,"ClusterHealth":[{"MemberID":9882886658148554927,"MemberIDHex":"8927110dc66458af","Name":"default","Err":"","Healthy":true}],"Header":{"cluster_id":4255616304056076734,"member_id":9882886658148554927,"raft_term":17}}
user@host-00:/var/log$ curl http://127.0.0.1:8080/version
{"etcd":{"etcdserver":"3.3.22","etcdcluster":"3.3.0"},"sensu_backend":"6.0.0"}

Given this stuff is only happening in my product AWS accounts I’m going to begin looking there. It’s running on a t3.medium in us-east-1c.

[Capt-Tom]

I was able to resolve this with both changes to the host I am deploying on and changes to the certificate. etcd has some documented weirdness with SSL, and with recent changes to the spec how v3 extensions are copied through from configuration to signing request and eventually the certificate it’s easy for a required component to not make it through as etcd or one of the sensu processes might expect. Ensure your host will resolve through all the means used in the certificate and ensure the certificate has matching CN and needed SANs. When reconfiguring a host ensure the state directory for etcd is clean or it may not purge your prior configuration.

ETCD with TLS showing error "transport: remote error: tls: bad certificate" for certificates generated using OpenSSL

At this point I’m fairly confident this unauthorized error trickles up when there’s an SSL misconfiguration afoot, in which case a more descriptive error message would be significantly helpful. If this message is generated in a variety of situations including but not limited to SSL issues then perhaps the language as is is acceptable.

When putting together a deployment like this it’s important to have your end state SSL configuration in mind so you don’t end up with local or private address space in a cert that might be running on ephemeral infrastructure.

[jspaleta]

Thanks for the update,

Based on your experience, do you have a quick checklist for certificate generation that covers your troubleshooting experience?

In our existing certificate guide is there something we need to add explicitly that would help people avoid problems when transitioning from the documented cert creation in the guide into using production using a production CA?

I believe the instructions for the sell-sgined certs in the certificate generation guide still work, but we might be able to enhance that guide with a note calling out specific certificate requirments, to help when people transition from the self-signed example into production certificate usage.

I guess what would also be really helpful is documenting the different ways tls cert verification can fail, so we can work on enhancing logging to better help operators track down the underlying problem.

[Capt-Tom]

Generation checklist:

1. CN matches first SAN
2. SANs include all address methods you will be connecting with, FQDN/IP
3. openssl text/noout output includes intended CN and extensions including SANs
4. Chain signed appropriately and terminated by self-signed root certificate
5. Root CA certificate installed
6. openssl s_client verifies connection on port you’re seeking to connect to; 3000,8080,8081

Most common failures for SSL/TLS verification are going to be CN/SAN/hostname/IP mismatch, when the certificate not valid for this host/connection, and incorrectly installed root certificates, which will result in an unable to verify message (Verify return code: 21)

Unfortunately I think SSL/TLS is just one of those things you need to know in order to be able to approach troubleshooting effectively. There’s also a lot more that can go wrong with the wiggle room a self-signed dev CA provides compared to your typical established production SSL workflow. Knowing the tools available is probably number one, and for figuring out what’s wrong with an SSL connection the general openssl s_client should be the starting point. Number two should be the concepts SSL/TLS uses to function, the chain of trust, what a root CA is. Number three is that this unauthorized error typically means there’s an issue with your SSL configuration; at least as far as I can tell. This is just something that might catch people unfamiliar with generating certs up.

Your existing certificate generation guide goes above and beyond what should be required for documentation on a piece of software’s SSL configuration, though if you’re connecting to a Sensu service, backend UI, agent API, or configuration API by IP, the certificates involved are going to require the IP address as a Subject Alternative Name. Your guide currently states localhost and loopback are included for convenience, but the protocol requires the target, either hostname or IP, be appropriately present in the certificate. Connecting via IP is going to be common while deploying or configuring an instance before final architecture, infrastructure, and DNS is all set. It might common, for instance, to configure an agent on the same host that your backend is running on. In this case if you try to hook the agent up to localhost or loopback, but did not provide the certificates with loopback in a SAN, your connection will fail.

Another thing I noticed that I didn’t look too closely at was that connections would sometimes fail when passing the root CA file in by itself but connections would succeed when passing in the system’s entire trust store, with the CA certificate appended on the end. This is more likely due to permissions or something than bugs in Sensu itself or TLS.

Either way thanks for the discourse as usual and hope all is well.