Logins denied by RBAC rules no longer generate audit log entries

[timothyb89]

In 6.0.1, login attempts when denied by RBAC rules generated audit log entries.

Example in 6.0.1 when principal is missing from certificate:

$ tsh ssh node
ERROR: access denied to tim connecting to node on cluster foo.example.com

...and the associated audit log entry:

{
  "addr.local": "127.0.0.1:3022",
  "addr.remote": "192.168.10.1:60180",
  "cluster_name": "",
  "code": "T3007W",
  "ei": 0,
  "error": "ssh: principal \"tim\" not in the set of valid principals for given certificate: [\"-teleport-nologin-a58cfc06-fd14-4952-83bf-995169799e49\"]",
  "event": "auth",
  "login": "tim",
  "success": false,
  "time": "2021-07-22T21:32:54.286Z",
  "uid": "c811a4a4-44ac-4d4f-8963-2e6a686ad614",
  "user": "tim2"
}

Similarly, if denied by node labels, the user sees this:

$ tsh ssh monitor
ERROR: access denied to tim connecting to node on cluster foo.example.com

... and an audit log entry is generated:

{
  "addr.local": "127.0.0.1:3022",
  "addr.remote": "192.168.10.1:60145",
  "cluster_name": "",
  "code": "T3007W",
  "ei": 0,
  "error": "user [email protected] is not authorized to login as [email protected]: access to server denied",
  "event": "auth",
  "login": "tim",
  "success": false,
  "time": "2021-07-22T21:31:48.917Z",
  "uid": "415609bf-e510-4c6c-b1e5-e1e660a68346",
  "user": "tim2"
}

Now in 7.0.0-beta.3, the user sees the following message in both cases:

$ tsh ssh node
ERROR: node "Node:\"node\" Login:\"tim\" " not found

In both cases, the proxy server logs the attempt as an authorization failure but no audit log is generated. Port forwarding attempts denied by RBAC rules do still generate audit log events in v7.0.0-beta.3.

v6.2.3 appears to behave the same as v7.0.0.

[Joerger]

I looked into this a bit and found that the audit log isn't created because IsMFARequired returns an error before the ssh connection is attempted.

Error returned by IsMFARequired: "Node:\"server01\" Login:\"bjoerger\" " not found

When I remove the MFA required check, I get:

Error: access denied to bjoerger.com connecting to server01 on cluster example.com
Audit log:

{
  "addr.local": "127.0.0.1:3022",
  "addr.remote": "127.0.0.1:41080",
  "cluster_name": "example.com",
  "code": "T3007W",
  "ei": 0,
  "error": "ssh: principal \"bjoerger\" not in the set of valid principals for given certificate: [\"-teleport-nologin-e8f76798-4892-4607-9384-702b1b401cc7\"]",
  "event": "auth",
  "login": "bjoerger",
  "success": false,
  "time": "2021-07-22T19:24:38.357Z",
  "uid": "bc3e9f92-6100-44b9-8e17-f140d59c36a5",
  "user": "dev"
}