log,allocatorimpl: log allocation messages to a separate log file

The allocator logs are written to the main log file, which means that those messages sometimes spam the main log, and also, we can't increase verbosity much. Because of that most allocation logs are now under a vlog and therefore rarely used. This PR moves all allocation logs to a separate channel. The next step would be to move some log messages from vlog to be printed always, which should help debugging. Note that some unit tests were relying on VEventf tracing, even when vmodule is not enabled, instead we now explicitly set vmodule in those tests. Step 1 for #82836. Release note: None
cockroachdb · Aug 9, 2022 · f5e8b0d · f5e8b0d
1 parent 24906bd
commit f5e8b0d
Show file tree

Hide file tree

Showing 18 changed files with 474 additions and 162 deletions.
diff --git a/docs/generated/logging.md b/docs/generated/logging.md
@@ -169,3 +169,7 @@ The `TELEMETRY` channel reports telemetry events. Telemetry events describe
 feature usage within CockroachDB and anonymizes any application-
 specific data.
 
+### `ALLOCATOR`
+
+The `ALLOCATOR` channel is used to report allocation and rebalancing events.
+
diff --git a/pkg/cli/log_flags.go b/pkg/cli/log_flags.go
@@ -456,6 +456,7 @@ func addPredefinedLogFiles(c *logconfig.Config) {
 const predefinedLogFiles = `
 sinks:
  file-groups:
+  allocator:              { channels: ALLOCATOR }
   default:
     channels:
       INFO: [DEV, OPS]

diff --git a/pkg/cli/testdata/logflags b/pkg/cli/testdata/logflags
@@ -15,7 +15,8 @@ start
 config: {<stdFileDefaults(<defaultLogDir>)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -27,7 +28,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],<defaultLogDir>,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],<defaultLogDir>,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],<defaultLogDir>,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -49,7 +51,8 @@ start-single-node
 config: {<stdFileDefaults(<defaultLogDir>)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -61,7 +64,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],<defaultLogDir>,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],<defaultLogDir>,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],<defaultLogDir>,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -148,7 +152,8 @@ start
 config: {<stdFileDefaults(/pathA/logs)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],/pathA/logs,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -160,7 +165,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],/pathA/logs,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],/pathA/logs,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],/pathA/logs,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],/pathA/logs,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -184,7 +190,8 @@ start
 config: {<stdFileDefaults(/mypath)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],/mypath,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -196,7 +203,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],/mypath,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],/mypath,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],/mypath,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],/mypath,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -221,7 +229,8 @@ start
 config: {<stdFileDefaults(/pathA/logs)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],/pathA/logs,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -233,7 +242,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],/pathA/logs,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],/pathA/logs,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],/pathA/logs,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],/pathA/logs,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -263,7 +273,8 @@ start
 config: {<stdFileDefaults(/mypath)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],/mypath,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -275,7 +286,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],/mypath,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],/mypath,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],/mypath,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],/mypath,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -298,7 +310,8 @@ start
 config: {<stdFileDefaults(<defaultLogDir>)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -310,7 +323,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],<defaultLogDir>,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],<defaultLogDir>,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],<defaultLogDir>,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -334,7 +348,8 @@ start
 config: {<stdFileDefaults(<defaultLogDir>)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -346,7 +361,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],<defaultLogDir>,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],<defaultLogDir>,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],<defaultLogDir>,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -379,7 +395,8 @@ start
 config: {<stdFileDefaults(<defaultLogDir>)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -391,7 +408,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],<defaultLogDir>,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],<defaultLogDir>,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],<defaultLogDir>,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -447,7 +465,8 @@ start
 config: {<stdFileDefaults(/mypath)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],/mypath,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -459,7 +478,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],/mypath,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],/mypath,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],/mypath,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],/mypath,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -484,7 +504,8 @@ start
 config: {<stdFileDefaults(/pathA)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],/pathA,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -496,7 +517,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],/pathA,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],/pathA,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],/pathA,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],/pathA,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -540,7 +562,8 @@ start
 config: {<stdFileDefaults(<defaultLogDir>)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -552,7 +575,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],<defaultLogDir>,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],<defaultLogDir>,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],<defaultLogDir>,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,
@@ -575,7 +599,8 @@ start
 config: {<stdFileDefaults(<defaultLogDir>)>,
 <fluentDefaults>,
 <httpDefaults>,
-sinks: {file-groups: {default: <fileCfg(INFO: [DEV,
+sinks: {file-groups: {allocator: <fileCfg(INFO: [ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
+default: <fileCfg(INFO: [DEV,
 OPS],
 WARNING: [HEALTH,
 STORAGE,
@@ -587,7 +612,8 @@ SENSITIVE_ACCESS,
 SQL_EXEC,
 SQL_PERF,
 SQL_INTERNAL_PERF,
-TELEMETRY],<defaultLogDir>,true,crdb-v2)>,
+TELEMETRY,
+ALLOCATOR],<defaultLogDir>,true,crdb-v2)>,
 health: <fileCfg(INFO: [HEALTH],<defaultLogDir>,true,crdb-v2)>,
 pebble: <fileCfg(INFO: [STORAGE],<defaultLogDir>,true,crdb-v2)>,
 security: <fileCfg(INFO: [USER_ADMIN,