server,log: report tenant names in logging output #108807

knz · 2023-08-15T20:33:41Z

Prior to this change, the tenant details reported in logging output
were limited to just the tenant ID. This is because the original
tenant server initialization code only had access to the tenant
ID (provided as CLI argument).

Since recently, the tenant name is also becoming known during tenant
server initialization. This is currently done via the tenant
connector.

This commit expands on this foundation by injecting the tenant name
into the logging output as soon as it is available.

For example:

I230815 19:31:07.290757 922 sql/temporary_schema.go:554 ⋮ [T4,Vblah,n1] 148  found 0 temporary schemas
                                                              ^^^^^ here

or using JSON:

{"channel_numeric":0,"channel":"DEV",...,"tenant_id":4,"tenant_name":"blah",...}
                                                       ^^^^^^^^^^^^^^^^^^^^ here

Note: we are choosing to report the tenant name in addition to the
tenant ID to preserve compatibilit with automation (eg. logspy) which
needs to filter entries based on ID.

Release note (cluster virtualization): The name of the virtual
cluster (tenant), when known, is now reported in logging events.
Refer to the documentation of individual logging format for details.

cockroach-teamcity · 2023-08-15T20:34:31Z

This change is

stevendanna

Thanks for all the nice small cleanups that you did along the way here.

I left minor comments and question, take those that are useful, leave the rest.

While reading I had the vague sense of "V seems like a letter we might want in the future for something else" with respect to the log tag. But, staring at my keyboard I don't see a letter I like particularly better.

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

pkg/server/server_sql.go line 1422 at r5 (raw file):

		if entry, _ := s.tenantConnect.TenantInfo(); entry.Name != "" {
			s.cfg.idProvider.SetTenantName(entry.Name)
		}

Perhaps we should comment on the behaviour on RENAME.

It looks to me like rename isn't handled currently. I'm OK with not handling it yet. I think we could probably handle it by extending our startCheckService routine to also update the name if it sees a name update during its polling.

pkg/util/log/format_crdb.go line 28 at r5 (raw file):

// tenantNameLogTagKey is the log tag key used when tagging
// log entries with a tenant name.
const tenantNameLogTagKey = 'V'

I imagine this is V for "Virtual Cluster"?

pkg/util/log/format_crdb_v1.go line 342 at r5 (raw file):

// and a size estimate for the printout of the label.
func checkTenantLabel(tenantID string, tenantName string) (hasLabel bool, length int) {
	return tenantID != "", len(tenantID) + len("T,L,") + len(tenantName)

It doesn't matter for the size estimate. But what is the L here?

pkg/util/log/format_crdb_v2.go line 722 at r5 (raw file):

func (f entryDecoderV2Fragment) getTenantDetails() (tenantID, tenantName string) {
	tags := f[v2TagsIdx]
	if bytes.Equal(tags, []byte("-")) {

This is in the existing code as well, but it could be helpful to move this to a constant just so we can put a comment on it that explains what it is a marker for.

pkg/util/log/format_json.go line 260 at r5 (raw file):

}

const serverIdentifierFields = "NxqTL"

Should this be s/L/V/?

pkg/util/log/format_crdb_v1_test.go line 205 at r5 (raw file):

	tc := []struct {
		in            string
		expOut        string

[nit] expRemainder might be a slightly better name.

knz

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @abarganier and @stevendanna)

pkg/server/server_sql.go line 1422 at r5 (raw file):