Skip to content

Commit

Permalink
sql,log: productionize the event logging
Browse files Browse the repository at this point in the history
CockroachDB needs to report structured events for "important" events
on the logical structure of a cluster, including changes to the SQL
logical schema, node activity, privilege changes etc.

Prior to this patch, these events were reported mainly into the
table `system.eventlog`, with a partial copy of the payload into the
debugging external log (`cockroach.log`).

This solution was incomplete and unsatisfactory in many ways:

- the event payloads were not documented.

- the event payloads were not centrally defined, which was preventing
  the generation of automatic documentation.

- the payload types were declared "inline" in the log calls, which
  made it easy for team members to inadvertently change the structure of
  the payload and make them backward-incompatible for users consuming
  this data externally.

- the payload fields were inconsistently named across event types.

- the metadata fields on the payloads were incompletely and
  inconsistently populated:

  - the SQL instance ID was missing in some cases.
  - the descriptor ID of affected descriptor was missing in some
    cases.

- the same event type was mistakenly used for different events (e.g.
  "rename_database" for both RENAME DATABASE and CONVERT TO SCHEMA)

- the same event type was abusingly over-used for multiple separate
  operations, e.g. a single event would be generated for a multi-table,
  multi-user GRANT or REVOKE operation.

- the copy in the external log was not parseable. Generally, the
  logging package was unaware of the internal structure of events
  and would “flatten” them.

- no provision was available to partially redact events. From the
  logging system's perspective, the entire payload is sensitive.

This commit changes the situation as follows:

- it centralizes the payload definitions and standardizes them into a
  new package `eventspb`.
- it enables automatic generation of documentation for events.
- it ensures that field names are consistent across event payloads.
- it ensures that event metadata is consistently populted.
- it decomposes complex GRANT/REVOKE operations into individual
  events.

(FIXME - remaining to be done:)

- it automates the generation of a reference documentation for all
  event types.
- it provide a guardrail against the introduction of new DDL
  statements without a corresponding event log.

The following problems continue to exist and need to be resolved
separately:

- privilege changes that occur as a side effect of certain operations
  do not get events logged:

  cockroachdb#57573
  cockroachdb#57576

- the name fields in certain DDL events is not properly qualified,
  which prevents the determination of the logical schema or database
  where the object was altered:

  cockroachdb#57734
  cockroachdb#57735

Release note (sql change): FIXME
  • Loading branch information
knz committed Dec 9, 2020
1 parent aa69b42 commit 9c71171
Show file tree
Hide file tree
Showing 16 changed files with 16,993 additions and 151 deletions.
17 changes: 5 additions & 12 deletions pkg/sql/create_database.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sem/tree"
"github.com/cockroachdb/cockroach/pkg/sql/sqltelemetry"
"github.com/cockroachdb/cockroach/pkg/util/errorutil/unimplemented"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
)

type createDatabaseNode struct {
Expand Down Expand Up @@ -107,18 +108,10 @@ func (n *createDatabaseNode) startExec(params runParams) error {
if created {
// Log Create Database event. This is an auditable log event and is
// recorded in the same transaction as the table descriptor update.
if err := MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
params.ctx,
params.p.txn,
EventLogCreateDatabase,
int32(desc.GetID()),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
DatabaseName string
Statement string
User string
}{n.n.Name.String(), n.n.String(), params.p.User().Normalized()},
); err != nil {
if err := params.p.logEvent(params.ctx, desc.GetID(),
&eventpb.CreateDatabase{
DatabaseName: n.n.Name.String(),
}); err != nil {
return err
}
}
Expand Down
20 changes: 7 additions & 13 deletions pkg/sql/drop_database.go
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sessiondata"
"github.com/cockroachdb/cockroach/pkg/sql/sqltelemetry"
"github.com/cockroachdb/cockroach/pkg/util/log"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/errors"
)

Expand Down Expand Up @@ -195,19 +196,12 @@ func (n *dropDatabaseNode) startExec(params runParams) error {

// Log Drop Database event. This is an auditable log event and is recorded
// in the same transaction as the table descriptor update.
return MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
ctx,
p.txn,
EventLogDropDatabase,
int32(n.dbDesc.GetID()),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
DatabaseName string
Statement string
User string
DroppedSchemaObjects []string
}{n.n.Name.String(), n.n.String(), p.User().Normalized(), n.d.droppedNames},
)
return p.logEvent(ctx,
n.dbDesc.GetID(),
&eventpb.DropDatabase{
DatabaseName: n.n.Name.String(),
DroppedSchemaObjects: n.d.droppedNames,
})
}

func (*dropDatabaseNode) Next(runParams) (bool, error) { return false, nil }
Expand Down
23 changes: 9 additions & 14 deletions pkg/sql/drop_table.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sessiondata"
"github.com/cockroachdb/cockroach/pkg/sql/sqltelemetry"
"github.com/cockroachdb/cockroach/pkg/util/errorutil/unimplemented"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/cockroach/pkg/util/timeutil"
"github.com/cockroachdb/errors"
)
Expand Down Expand Up @@ -134,20 +135,14 @@ func (n *dropTableNode) startExec(params runParams) error {
// Log a Drop Table event for this table. This is an auditable log event
// and is recorded in the same transaction as the table descriptor
// update.
if err := MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
ctx,
params.p.txn,
EventLogDropTable,
int32(droppedDesc.ID),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
TableName string
Statement string
User string
CascadeDroppedViews []string
}{toDel.tn.FQString(), n.n.String(),
params.p.User().Normalized(), droppedViews},
); err != nil {
if err := params.p.logEvent(params.ctx,
droppedDesc.ID,
&eventpb.DropTable{
TableName: toDel.tn.FQString(),
// TODO(knz): the droppedViews are insufficiently qualified
// See: https://github.com/cockroachdb/cockroach/issues/57735
CascadeDroppedViews: droppedViews,
}); err != nil {
return err
}
}
Expand Down
16 changes: 4 additions & 12 deletions pkg/sql/drop_type.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sem/tree"
"github.com/cockroachdb/cockroach/pkg/sql/sqltelemetry"
"github.com/cockroachdb/cockroach/pkg/util/errorutil/unimplemented"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/errors"
)

Expand Down Expand Up @@ -142,18 +143,9 @@ func (n *dropTypeNode) startExec(params runParams) error {
return err
}
// Log a Drop Type event.
if err := MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
params.ctx,
params.p.txn,
EventLogDropType,
int32(typ.ID),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
TypeName string
Statement string
User string
}{typ.Name, tree.AsStringWithFQNames(n.n, params.Ann()), params.p.User().Normalized()},
); err != nil {
// TODO(knz): This logging is imperfect, see this issue:
// https://github.com/cockroachdb/cockroach/issues/57734
if err := params.p.logEvent(params.ctx, typ.ID, &eventpb.DropType{TypeName: typ.Name}); err != nil {
return err
}
}
Expand Down
19 changes: 6 additions & 13 deletions pkg/sql/drop_view.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sqlerrors"
"github.com/cockroachdb/cockroach/pkg/sql/sqltelemetry"
"github.com/cockroachdb/cockroach/pkg/util/log"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/errors"
)

Expand Down Expand Up @@ -108,19 +109,11 @@ func (n *dropViewNode) startExec(params runParams) error {
// Log a Drop View event for this table. This is an auditable log event
// and is recorded in the same transaction as the table descriptor
// update.
if err := MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
ctx,
params.p.txn,
EventLogDropView,
int32(droppedDesc.ID),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
ViewName string
Statement string
User string
CascadeDroppedViews []string
}{toDel.tn.FQString(), n.n.String(), params.p.User().Normalized(), cascadeDroppedViews},
); err != nil {
if err := params.p.logEvent(ctx,
droppedDesc.ID,
&eventpb.DropView{
ViewName: toDel.tn.FQString(),
CascadeDroppedViews: cascadeDroppedViews}); err != nil {
return err
}
}
Expand Down
35 changes: 35 additions & 0 deletions pkg/sql/event_log.go
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,10 @@ import (
"encoding/json"

"github.com/cockroachdb/cockroach/pkg/kv"
"github.com/cockroachdb/cockroach/pkg/sql/catalog/descpb"
"github.com/cockroachdb/cockroach/pkg/sql/sem/tree"
"github.com/cockroachdb/cockroach/pkg/util/log"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/errors"
)

Expand Down Expand Up @@ -176,6 +179,38 @@ func MakeEventLogger(execCfg *ExecutorConfig) EventLogger {
return EventLogger{InternalExecutor: execCfg.InternalExecutor}
}

// logEvent logs an event using an event logger derived from the current planner.
func (p *planner) logEvent(
ctx context.Context, descID descpb.ID, event eventpb.EventPayload,
) error {
// Compute the common fields from data already known to the planner.
ts := p.extendedEvalCtx.TxnTimestamp
sqlInstanceID := p.extendedEvalCtx.NodeID.SQLInstanceID()
user := p.User().Normalized()
stmt := tree.AsStringWithFQNames(p.stmt.AST, p.extendedEvalCtx.EvalContext.Annotations)

// Inject the common fields into the payload provided by the caller.
event.CommonDetails().Timestamp = ts
sqlCommon, ok := event.(eventpb.EventWithCommonSQLPayload)
if !ok {
return errors.AssertionFailedf("unknown event type: %T", event)
}
m := sqlCommon.CommonSQLDetails()
m.Statement = stmt
m.User = user
m.InstanceID = int32(sqlInstanceID)
m.DescriptorID = uint32(descID)

// Delegate the storing of the event to the regular event logic.
return MakeEventLogger(p.extendedEvalCtx.ExecCfg).InsertEventRecord(
ctx,
p.txn,
EventLogType(eventpb.GetEventName(event)),
int32(descID),
int32(sqlInstanceID),
event)
}

// InsertEventRecord inserts a single event into the event log as part of the
// provided transaction.
func (ev EventLogger) InsertEventRecord(
Expand Down
20 changes: 7 additions & 13 deletions pkg/sql/rename_database.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sqlerrors"
"github.com/cockroachdb/cockroach/pkg/util"
"github.com/cockroachdb/cockroach/pkg/util/log"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/cockroach/pkg/util/sequence"
"github.com/cockroachdb/errors"
)
Expand Down Expand Up @@ -243,19 +244,12 @@ func (n *renameDatabaseNode) startExec(params runParams) error {

// Log Rename Database event. This is an auditable log event and is recorded
// in the same transaction as the table descriptor update.
return MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
ctx,
p.txn,
EventLogRenameDatabase,
int32(n.dbDesc.GetID()),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
DatabaseName string
Statement string
User string
NewDatabaseName string
}{n.n.Name.String(), n.n.String(), p.User().Normalized(), n.newName},
)
return p.logEvent(ctx,
n.dbDesc.GetID(),
&eventpb.RenameDatabase{
DatabaseName: n.n.Name.String(),
NewDatabaseName: n.newName,
})
}

// isAllowedDependentDescInRename determines when rename database is allowed with
Expand Down
20 changes: 7 additions & 13 deletions pkg/sql/rename_table.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sem/tree"
"github.com/cockroachdb/cockroach/pkg/sql/sqlerrors"
"github.com/cockroachdb/cockroach/pkg/util/log"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/errors"
)

Expand Down Expand Up @@ -257,19 +258,12 @@ func (n *renameTableNode) startExec(params runParams) error {

// Log Rename Table event. This is an auditable log event and is recorded
// in the same transaction as the table descriptor update.
return MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
params.ctx,
params.p.txn,
EventLogRenameTable,
int32(tableDesc.ID),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
TableName string
Statement string
User string
NewTableName string
}{oldTn.FQString(), n.n.String(), params.p.User().Normalized(), newTn.FQString()},
)
return p.logEvent(ctx,
tableDesc.ID,
&eventpb.RenameTable{
TableName: oldTn.FQString(),
NewTableName: newTn.FQString(),
})
}

func (n *renameTableNode) Next(runParams) (bool, error) { return false, nil }
Expand Down
19 changes: 7 additions & 12 deletions pkg/sql/reparent_database.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/sem/tree"
"github.com/cockroachdb/cockroach/pkg/sql/sqlerrors"
"github.com/cockroachdb/cockroach/pkg/sql/sqltelemetry"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/cockroach/pkg/util/protoutil"
"github.com/cockroachdb/errors"
)
Expand Down Expand Up @@ -297,18 +298,12 @@ func (n *reparentDatabaseNode) startExec(params runParams) error {

// Log Rename Database event. This is an auditable log event and is recorded
// in the same transaction as the table descriptor update.
return MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
ctx,
p.txn,
EventLogConvertToSchema,
int32(n.db.ID),
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
struct {
DatabaseName string
NewDatabaseName string
User string
}{n.db.Name, n.newParent.Name, p.User().Normalized()},
)
return p.logEvent(ctx,
n.db.ID,
&eventpb.ConvertToSchema{
DatabaseName: n.db.Name,
NewDatabaseParent: n.newParent.Name,
})
}

func (n *reparentDatabaseNode) Next(params runParams) (bool, error) { return false, nil }
Expand Down
13 changes: 6 additions & 7 deletions pkg/sql/set_cluster_setting.go
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/sql/types"
"github.com/cockroachdb/cockroach/pkg/util/humanizeutil"
"github.com/cockroachdb/cockroach/pkg/util/log"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/cockroach/pkg/util/protoutil"
"github.com/cockroachdb/cockroach/pkg/util/retry"
"github.com/cockroachdb/errors"
Expand Down Expand Up @@ -315,14 +316,12 @@ func (n *setClusterSettingNode) startExec(params runParams) error {
telemetry.Inc(sqltelemetry.VecModeCounter(validatedExecMode.String()))
}

return MakeEventLogger(params.extendedEvalCtx.ExecCfg).InsertEventRecord(
ctx,
txn,
EventLogSetClusterSetting,
return params.p.logEvent(ctx,
0, /* no target */
int32(params.extendedEvalCtx.NodeID.SQLInstanceID()),
EventLogSetClusterSettingDetail{n.name, reportedValue, params.p.User().Normalized()},
)
&eventpb.SetClusterSetting{
SettingName: n.name,
Value: reportedValue,
})
}); err != nil {
return err
}
Expand Down
Loading

0 comments on commit 9c71171

Please sign in to comment.