sql: Extend SQL audit logging to log operations run by admin users

[RichardJCai]

sql: Extend SQL audit logging to log operations run by admin users

Release note (sql change): SQL audit log can now be extended to track
operations run by admin users.
By enabling the cluster setting sql.log.admin_audit.enabled, the
sql-audit-log will note if a command has been run by an admin by
including "admin" in the log entry next to the statement.

Resolves #58334

[cockroach-teamcity]

This change is 

[RichardJCai]

Put out simple PR extending SQL audit log to track admin users.
We can call HasAdminRole on each statement since it's cached. Discussed here #59356 (review)

Need to update it so HasAdminRole is only called once per transaction (on the first statement) and add tests.

[RichardJCai]

Put out simple PR extending SQL audit log to track admin users.
We can call HasAdminRole on each statement since it's cached. Discussed here #59356 (review)

Need to update it so HasAdminRole is only called once per transaction (on the first statement) and add tests.

Also just double checking, it is reasonable to check only on the first statement of a transaction since a user that isn't admin cannot grant themselves a role with admin privilege without already being a member of that role already right? Or that they're admin. In short, a user cannot become an admin in the middle of a transaction if they weren't one at the start of the transaction.

[ajwerner]

Also just double checking, it is reasonable to check only on the first statement of a transaction since a user that isn't admin cannot grant themselves a role with admin privilege without already being a member of that role already right? Or that they're admin. In short, a user cannot become an admin in the middle of a transaction if they weren't one at the start of the transaction.

I think that that's right. You could cache it in the extraTxnState if you wanted.

Reviewed 1 of 1 files at r1.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @RichardJCai)

---

pkg/sql/exec_log.go, line 155 at r1 (raw file):

	auditEventsDetected := len(p.curPlan.auditEvents) != 0

	hasAdminRole, hasAdminRoleErr := p.HasAdminRole(ctx)

can we avoid doing this check if admin audit logging is not enabled?

---

pkg/sql/exec_log.go, line 156 at r1 (raw file):

	hasAdminRole, hasAdminRoleErr := p.HasAdminRole(ctx)
	log.Warningf(ctx, "checking hasAdminRole failed %v", hasAdminRoleErr)

this type of logging, for all of its good intentions, can get spammy if it happens on every statement (which it very well may). Honestly, if you're going to do something here other than fatal, please wrap it in a log.Every that you hang off the execcfg or something like that? maybe I'm too paranoid

[knz]

Thanks for taking a stab at this.

The general issue with the current approach is that it checks too late for the admin role. The check for the admin role must be done prior to execution, not afterwards.

Reviewed 10 of 10 files at r2.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @ajwerner, @rafiss, and @RichardJCai)

---

pkg/sql/exec_log.go, line 155 at r1 (raw file):

Previously, ajwerner wrote…

can we avoid doing this check if admin audit logging is not enabled?

+1

---

pkg/sql/exec_log.go, line 163 at r2 (raw file):

	hasAdminRole := false
	// Only try to log to the admin audit log if the statement was explicitly

Why the extra condition? Why not always log if admin logging is enabled?

---

pkg/sql/exec_log.go, line 170 at r2 (raw file):

		} else {
			var hasAdminRoleErr error
			hasAdminRole, hasAdminRoleErr = p.HasAdminRole(ctx)

No, this is not the right place to test this. If admin logging is enabled, the check must be done at the very beginning of the transaction, before the first statement is executed. By the time maybeLogStatement is reached, the txn may not be valid any more (eg after an error).

---

pkg/sql/exec_log.go, line 174 at r2 (raw file):

			hasAdminRoleCache.IsSet = true
			if hasAdminRoleErr != nil {
				log.Fatalf(ctx, "checking hasAdminRole failed %v", hasAdminRoleErr)

Certainly not a fatal error here 😂

Make the sql return an error if the check fails. If admin logging is enabled and the admin role can't be ascertained, there are serious issues at hand, and we can afford to fail the sql txn altogether.

---

pkg/sql/exec_log.go, line 226 at r2 (raw file):

		// Now log!
		if auditEventsDetected || shouldLogToAdminAuditLog {

the legacy format is obsolete, please don't extend it

---

pkg/sql/exec_log.go, line 243 at r2 (raw file):

				sep = ", "
			}
			if shouldLogToAdminAuditLog {

ditto

[RichardJCai]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @rafiss)

---

pkg/sql/exec_log.go, line 163 at r2 (raw file):

Previously, knz (kena) wrote…

Why the extra condition? Why not always log if admin logging is enabled?

Removed extra condition.

---

pkg/sql/exec_log.go, line 170 at r2 (raw file):

Previously, knz (kena) wrote…

No, this is not the right place to test this. If admin logging is enabled, the check must be done at the very beginning of the transaction, before the first statement is executed. By the time maybeLogStatement is reached, the txn may not be valid any more (eg after an error).

Moved it to before the defer maybeLogStatement (to the top of dispatchToExecutionEngine)

---

pkg/sql/exec_log.go, line 174 at r2 (raw file):

Previously, knz (kena) wrote…

Certainly not a fatal error here 😂

Make the sql return an error if the check fails. If admin logging is enabled and the admin role can't be ascertained, there are serious issues at hand, and we can afford to fail the sql txn altogether.

Updated to return sql err

---

pkg/sql/exec_log.go, line 226 at r2 (raw file):

Previously, knz (kena) wrote…

the legacy format is obsolete, please don't extend it

Done.

---

pkg/sql/exec_log.go, line 243 at r2 (raw file):

Previously, knz (kena) wrote…

ditto

Done.

[knz]

Nice, this is almost good to go.

The release note is broken though. Try this:

Release note (security update): It is now possible to log
SQL statements executed by admin users. This logging
is enabled via the cluster `setting sql.log.admin_audit.enabled`.
When set, events of type `admin_query` are logged to
the SENSITIVE_ACCESS channel.

Reviewed 4 of 4 files at r3.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @rafiss and @RichardJCai)

---

pkg/sql/admin_audit_log_test.go, line 121 at r3 (raw file):

	_, err = testuser.Exec(`SELECT 1`)
	if err != nil {

nit: if _, err := ...; err != nil

---

pkg/sql/admin_audit_log_test.go, line 250 at r3 (raw file):

	db.Exec(t, `GRANT admin TO testuser`)

	_, err = testuser.Exec(`

ditto

---

pkg/sql/conn_executor_exec.go, line 817 at r3 (raw file):

	// We must check prior to execution in the case the txn is aborted due to
	// an error. HasAdminRole can only be checked in a valid txn.
	adminAuditLog := adminAuditLogEnabled.Get(&ex.planner.execCfg.Settings.SV)

nit: if adminAuditLog := ...; adminAuditLog { ... }

---

pkg/sql/conn_executor_exec.go, line 851 at r3 (raw file):

			ex.extraTxnState.autoRetryCounter,
			res.RowsAffected(),
			res,

why did this need to change?

---

pkg/sql/exec_log.go, line 161 at r3 (raw file):

	slowInternalQueryLogEnabled := slowInternalQueryLogEnabled.Get(&p.execCfg.Settings.SV)
	auditEventsDetected := len(p.curPlan.auditEvents) != 0
	adminAuditLog := adminAuditLogEnabled.Get(&p.execCfg.Settings.SV)

You don't need to re-read the adminAuditLog setting here. If hasAdminRoleCache.IsSet is true, then necessarily the cluster setting was enabled and a logging event must be emitted.

---

pkg/sql/exec_log.go, line 167 at r3 (raw file):

		// hasAdminRoleCache should always be set before the deferred maybeLogStatement
		// in dispatchToExecutionEngine. If it is not set, we have a problem.
		if !hasAdminRoleCache.IsSet {

You're meaning to have an assertion here right? This can't happen without a bug?
In this case I would do logcrash.ReportOrPanic with an errors.AssertionFailedf as argument. No need to change res.

[RichardJCai]

Release note (security update): It is now possible to log
SQL statements executed by admin users. This logging
is enabled via the cluster setting sql.log.admin_audit.enabled.
When set, events of type admin_query are logged to
the SENSITIVE_ACCESS channel.

Updated

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @rafiss)

---

pkg/sql/admin_audit_log_test.go, line 250 at r3 (raw file):

Previously, knz (kena) wrote…

ditto

Done.

---

pkg/sql/conn_executor_exec.go, line 851 at r3 (raw file):

Previously, knz (kena) wrote…

why did this need to change?

Reverted

---

pkg/sql/exec_log.go, line 161 at r3 (raw file):

Previously, knz (kena) wrote…

You don't need to re-read the adminAuditLog setting here. If hasAdminRoleCache.IsSet is true, then necessarily the cluster setting was enabled and a logging event must be emitted.

Done.

---

pkg/sql/exec_log.go, line 167 at r3 (raw file):

Previously, knz (kena) wrote…

You're meaning to have an assertion here right? This can't happen without a bug?
In this case I would do logcrash.ReportOrPanic with an errors.AssertionFailedf as argument. No need to change res.

Removed this logic

[knz]

(NB I think you can simplify further a bit)

Reviewed 3 of 3 files at r4.
Reviewable status: complete! 1 of 0 LGTMs obtained (waiting on @rafiss)

---

pkg/sql/exec_log.go, line 167 at r3 (raw file):

Previously, RichardJCai (Richard Cai) wrote…

Removed this logic

NB: your current code is equivalent to a := false; if b { a = b && c }
which means that you can simplify to a := b && c right away.

[RichardJCai]

Reviewable status: complete! 1 of 0 LGTMs obtained (waiting on @rafiss)

---

pkg/sql/exec_log.go, line 167 at r3 (raw file):

Previously, knz (kena) wrote…

NB: your current code is equivalent to a := false; if b { a = b && c }
which means that you can simplify to a := b && c right away.

Done

[RichardJCai]

Thanks for reviewing!

bors r=knz

[craig]

Build succeeded:

• GitHub CI (Cockroach)