Merge #55364

55364: cli,server: fix the profile file name generation r=tbg a=knz Fixes #54723 Prior to this patch, the timestamp part in the profile filenames was using go format `.999` for the millisecond part. However, `.999` causes the millisecond part to be omitted entirely if they happen to be zero. The correct format was in fact `.000`. Release note (bug fix): The file names for generated goroutine, CPU and memory profiles were sometimes incorrect, resulting in repeated warnings like `strconv.ParseUint: parsing "txt": invalid syntax` in log files. This has been corrected. Co-authored-by: Raphael 'kena' Poss <knz@thaumogen.net>
cockroachdb · Oct 9, 2020 · 242565d · 242565d
2 parents 7f02a7a + a727378
commit 242565d
Show file tree

Hide file tree

Showing 5 changed files with 23 additions and 15 deletions.
diff --git a/pkg/cli/cpuprofile.go b/pkg/cli/cpuprofile.go
@@ -34,7 +34,7 @@ var maxCombinedCPUProfFileSize = settings.RegisterByteSizeSetting(
 	128<<20, // 128MiB
 )
 
-const cpuProfTimeFormat = "2006-01-02T15_04_05.999"
+const cpuProfTimeFormat = "2006-01-02T15_04_05.000"
 const cpuProfFileNamePrefix = "cpuprof."
 
 type cpuProfiler struct{}

diff --git a/pkg/server/goroutinedumper/goroutinedumper.go b/pkg/server/goroutinedumper/goroutinedumper.go
@@ -29,7 +29,7 @@ import (
 
 const (
 	goroutineDumpPrefix = "goroutine_dump"
-	timeFormat          = "2006-01-02T15_04_05.999"
+	timeFormat          = "2006-01-02T15_04_05.000"
 )
 
 var (

diff --git a/pkg/server/goroutinedumper/goroutinedumper_test.go b/pkg/server/goroutinedumper/goroutinedumper_test.go
@@ -61,9 +61,9 @@ func TestHeuristic(t *testing.T) {
 				{220, 100, 500}, // trigger since N has doubled since last dump
 			},
 			expectedDumps: []string{
-				"goroutine_dump.2019-01-01T00_00_20.double_since_last_dump.000000120",
-				"goroutine_dump.2019-01-01T00_01_20.double_since_last_dump.000000250",
-				"goroutine_dump.2019-01-01T00_03_40.double_since_last_dump.000000500",
+				"goroutine_dump.2019-01-01T00_00_20.000.double_since_last_dump.000000120",
+				"goroutine_dump.2019-01-01T00_01_20.000.double_since_last_dump.000000250",
+				"goroutine_dump.2019-01-01T00_03_40.000.double_since_last_dump.000000500",
 			},
 		},
 		{
@@ -84,12 +84,12 @@ func TestHeuristic(t *testing.T) {
 				{220, 100, 500}, // not trigger since N has not doubled since last dump
 			},
 			expectedDumps: []string{
-				"goroutine_dump.2019-01-01T00_00_20.double_since_last_dump.000000110",
-				"goroutine_dump.2019-01-01T00_01_40.double_since_last_dump.000000220",
-				"goroutine_dump.2019-01-01T00_03_20.double_since_last_dump.000000450",
+				"goroutine_dump.2019-01-01T00_00_20.000.double_since_last_dump.000000110",
+				"goroutine_dump.2019-01-01T00_01_40.000.double_since_last_dump.000000220",
+				"goroutine_dump.2019-01-01T00_03_20.000.double_since_last_dump.000000450",
 			},
 			dumpsToFail: []string{
-				"goroutine_dump.2019-01-01T00_01_20.double_since_last_dump.000000230",
+				"goroutine_dump.2019-01-01T00_01_20.000.double_since_last_dump.000000230",
 			},
 		},
 		{
@@ -109,9 +109,9 @@ func TestHeuristic(t *testing.T) {
 				{220, 200, 500}, // trigger since N has doubled since last dump
 			},
 			expectedDumps: []string{
-				"goroutine_dump.2019-01-01T00_00_20.double_since_last_dump.000000120",
-				"goroutine_dump.2019-01-01T00_01_30.double_since_last_dump.000000210",
-				"goroutine_dump.2019-01-01T00_03_40.double_since_last_dump.000000500",
+				"goroutine_dump.2019-01-01T00_00_20.000.double_since_last_dump.000000120",
+				"goroutine_dump.2019-01-01T00_01_30.000.double_since_last_dump.000000210",
+				"goroutine_dump.2019-01-01T00_03_40.000.double_since_last_dump.000000500",
 			},
 		},
 		{

diff --git a/pkg/server/heapprofiler/profiler_common.go b/pkg/server/heapprofiler/profiler_common.go
@@ -34,7 +34,7 @@ var resetHighWaterMarkInterval = func() time.Duration {
 // timestampFormat is chosen to mimic that used by the log
 // package. This is not a hard requirement though; the profiles are
 // stored in a separate directory.
-const timestampFormat = "2006-01-02T15_04_05.999"
+const timestampFormat = "2006-01-02T15_04_05.000"
 
 type testingKnobs struct {
 	dontWriteProfiles    bool

diff --git a/pkg/server/heapprofiler/profilestore_test.go b/pkg/server/heapprofiler/profilestore_test.go
@@ -24,13 +24,21 @@ import (
 )
 
 func TestMakeFileName(t *testing.T) {
-	ts := time.Date(2020, 6, 15, 13, 19, 19, 543000000, time.UTC)
-
 	store := dumpstore.NewStore("mydir", nil, nil)
 	joy := newProfileStore(store, HeapFileNamePrefix, ".test", nil)
+
+	ts := time.Date(2020, 6, 15, 13, 19, 19, 543000000, time.UTC)
 	assert.Equal(t,
 		filepath.Join("mydir", "memprof.2020-06-15T13_19_19.543.123456.test"),
 		joy.makeNewFileName(ts, 123456))
+
+	// Also check when the millisecond part is zero. This verifies that
+	// the .999 format is not used, which would cause the millisecond
+	// part to be (erronously) omitted.
+	ts = time.Date(2020, 6, 15, 13, 19, 19, 00000000, time.UTC)
+	assert.Equal(t,
+		filepath.Join("mydir", "memprof.2020-06-15T13_19_19.000.123456.test"),
+		joy.makeNewFileName(ts, 123456))
 }
 
 func TestParseFileName(t *testing.T) {