From b5a02c419041f49200281778ae8f3d98a0d3df75 Mon Sep 17 00:00:00 2001 From: iamchuckss Date: Mon, 18 May 2020 19:59:29 +0800 Subject: [PATCH] Fix log timestamps to be displayed in fixed width --- pkg/apis/core/types.go | 2 +- pkg/kubelet/kuberuntime/logs/BUILD | 1 + pkg/kubelet/kuberuntime/logs/logs.go | 13 ++++++++----- pkg/kubelet/kuberuntime/logs/logs_test.go | 8 ++++---- pkg/kubelet/types/constants.go | 5 +++++ pkg/kubelet/types/types.go | 8 ++++---- 6 files changed, 23 insertions(+), 14 deletions(-) diff --git a/pkg/apis/core/types.go b/pkg/apis/core/types.go index 3944d5dcadc..9418a118eac 100644 --- a/pkg/apis/core/types.go +++ b/pkg/apis/core/types.go @@ -4252,7 +4252,7 @@ type PodLogOptions struct { // If this value is in the future, no logs will be returned. // Only one of sinceSeconds or sinceTime may be specified. SinceTime *metav1.Time - // If true, add an RFC3339 or RFC3339Nano timestamp at the beginning of every line + // If true, add an RFC 3339 timestamp with 9 digits of fractional seconds at the beginning of every line // of log output. Timestamps bool // If set, the number of lines from the end of the logs to show. If not specified, diff --git a/pkg/kubelet/kuberuntime/logs/BUILD b/pkg/kubelet/kuberuntime/logs/BUILD index 18b4c8ec45a..42cde17e300 100644 --- a/pkg/kubelet/kuberuntime/logs/BUILD +++ b/pkg/kubelet/kuberuntime/logs/BUILD @@ -6,6 +6,7 @@ go_library( importpath = "k8s.io/kubernetes/pkg/kubelet/kuberuntime/logs", visibility = ["//visibility:public"], deps = [ + "//pkg/kubelet/types:go_default_library", "//pkg/util/tail:go_default_library", "//staging/src/k8s.io/api/core/v1:go_default_library", "//staging/src/k8s.io/cri-api/pkg/apis:go_default_library", diff --git a/pkg/kubelet/kuberuntime/logs/logs.go b/pkg/kubelet/kuberuntime/logs/logs.go index 4bff06de2d4..80809fa4e7a 100644 --- a/pkg/kubelet/kuberuntime/logs/logs.go +++ b/pkg/kubelet/kuberuntime/logs/logs.go @@ -35,6 +35,7 @@ import ( "k8s.io/api/core/v1" internalapi "k8s.io/cri-api/pkg/apis" runtimeapi "k8s.io/cri-api/pkg/apis/runtime/v1alpha2" + "k8s.io/kubernetes/pkg/kubelet/types" "k8s.io/kubernetes/pkg/util/tail" ) @@ -47,8 +48,10 @@ import ( // TODO(random-liu): Support log rotation. const ( - // timeFormat is the time format used in the log. - timeFormat = time.RFC3339Nano + // timeFormatOut is the format for writing timestamps to output. + timeFormatOut = types.RFC3339NanoFixed + // timeFormatIn is the format for parsing timestamps from other logs. + timeFormatIn = types.RFC3339NanoLenient // logForceCheckPeriod is the period to check for a new read logForceCheckPeriod = 1 * time.Second @@ -128,9 +131,9 @@ func parseCRILog(log []byte, msg *logMessage) error { if idx < 0 { return fmt.Errorf("timestamp is not found") } - msg.timestamp, err = time.Parse(timeFormat, string(log[:idx])) + msg.timestamp, err = time.Parse(timeFormatIn, string(log[:idx])) if err != nil { - return fmt.Errorf("unexpected timestamp format %q: %v", timeFormat, err) + return fmt.Errorf("unexpected timestamp format %q: %v", timeFormatIn, err) } // Parse stream type @@ -238,7 +241,7 @@ func (w *logWriter) write(msg *logMessage) error { } line := msg.log if w.opts.timestamp { - prefix := append([]byte(msg.timestamp.Format(timeFormat)), delimiter[0]) + prefix := append([]byte(msg.timestamp.Format(timeFormatOut)), delimiter[0]) line = append(prefix, line...) } // If the line is longer than the remaining bytes, cut it. diff --git a/pkg/kubelet/kuberuntime/logs/logs_test.go b/pkg/kubelet/kuberuntime/logs/logs_test.go index 493f2bd968d..f53b93037e6 100644 --- a/pkg/kubelet/kuberuntime/logs/logs_test.go +++ b/pkg/kubelet/kuberuntime/logs/logs_test.go @@ -67,7 +67,7 @@ func TestLogOptions(t *testing.T) { } func TestParseLog(t *testing.T) { - timestamp, err := time.Parse(timeFormat, "2016-10-20T18:39:20.57606443Z") + timestamp, err := time.Parse(timeFormatIn, "2016-10-20T18:39:20.57606443Z") assert.NoError(t, err) msg := &logMessage{} for c, test := range []struct { @@ -143,7 +143,7 @@ func TestParseLog(t *testing.T) { } func TestWriteLogs(t *testing.T) { - timestamp := time.Unix(1234, 4321) + timestamp := time.Unix(1234, 43210) log := "abcdefg\n" for c, test := range []struct { @@ -168,7 +168,7 @@ func TestWriteLogs(t *testing.T) { { // timestamp enabled stream: runtimeapi.Stderr, timestamp: true, - expectStderr: timestamp.Format(timeFormat) + " " + log, + expectStderr: timestamp.Format(timeFormatOut) + " " + log, }, } { t.Logf("TestCase #%d: %+v", c, test) @@ -189,7 +189,7 @@ func TestWriteLogs(t *testing.T) { func TestWriteLogsWithBytesLimit(t *testing.T) { timestamp := time.Unix(1234, 4321) - timestampStr := timestamp.Format(timeFormat) + timestampStr := timestamp.Format(timeFormatOut) log := "abcdefg\n" for c, test := range []struct { diff --git a/pkg/kubelet/types/constants.go b/pkg/kubelet/types/constants.go index f2f703a8d2b..378c23efb2e 100644 --- a/pkg/kubelet/types/constants.go +++ b/pkg/kubelet/types/constants.go @@ -29,4 +29,9 @@ const ( SystemReservedEnforcementKey = "system-reserved" KubeReservedEnforcementKey = "kube-reserved" NodeAllocatableNoneKey = "none" + + // fixed width version of time.RFC3339Nano + RFC3339NanoFixed = "2006-01-02T15:04:05.000000000Z07:00" + // variable width RFC3339 time format for lenient parsing of strings into timestamps + RFC3339NanoLenient = "2006-01-02T15:04:05.999999999Z07:00" ) diff --git a/pkg/kubelet/types/types.go b/pkg/kubelet/types/types.go index 9c8f165ffe6..a840e7de84e 100644 --- a/pkg/kubelet/types/types.go +++ b/pkg/kubelet/types/types.go @@ -43,10 +43,10 @@ func NewTimestamp() *Timestamp { return &Timestamp{time.Now()} } -// ConvertToTimestamp takes a string, parses it using the RFC3339Nano layout, +// ConvertToTimestamp takes a string, parses it using the RFC3339NanoLenient layout, // and converts it to a Timestamp object. func ConvertToTimestamp(timeString string) *Timestamp { - parsed, _ := time.Parse(time.RFC3339Nano, timeString) + parsed, _ := time.Parse(RFC3339NanoLenient, timeString) return &Timestamp{parsed} } @@ -55,10 +55,10 @@ func (t *Timestamp) Get() time.Time { return t.time } -// GetString returns the time in the string format using the RFC3339Nano +// GetString returns the time in the string format using the RFC3339NanoFixed // layout. func (t *Timestamp) GetString() string { - return t.time.Format(time.RFC3339Nano) + return t.time.Format(RFC3339NanoFixed) } // A type to help sort container statuses based on container names.