From 25c646cbdd90bd890fcc3fc3b350737ecccbdc19 Mon Sep 17 00:00:00 2001
From: Patrick Ohly <patrick.ohly@intel.com>
Date: Mon, 10 Jan 2022 16:07:30 +0100
Subject: [PATCH] json: never call fsync for stdout or stderr

We don't need to worry about data loss once the data has been written to an
output stream. Calling fsync unnecessarily has been the reason for performance
issues in the past.
---
 .../k8s.io/component-base/logs/json/json.go   | 26 +++++++++++++++++--
 .../logs/benchmark/benchmark_test.go          | 21 ++++++++-------
 2 files changed, 36 insertions(+), 11 deletions(-)

diff --git a/staging/src/k8s.io/component-base/logs/json/json.go b/staging/src/k8s.io/component-base/logs/json/json.go
index 1adada10cd4..a39a60dcd05 100644
--- a/staging/src/k8s.io/component-base/logs/json/json.go
+++ b/staging/src/k8s.io/component-base/logs/json/json.go
@@ -17,6 +17,7 @@ limitations under the License.
 package logs
 
 import (
+	"io"
 	"os"
 	"time"
 
@@ -83,9 +84,17 @@ type Factory struct{}
 var _ registry.LogFormatFactory = Factory{}
 
 func (f Factory) Create(options config.FormatOptions) (logr.Logger, func()) {
-	stderr := zapcore.Lock(os.Stderr)
+	// We intentionally avoid all os.File.Sync calls. Output is unbuffered,
+	// therefore we don't need to flush, and calling the underlying fsync
+	// would just slow down writing.
+	//
+	// The assumption is that logging only needs to ensure that data gets
+	// written to the output stream before the process terminates, but
+	// doesn't need to worry about data not being written because of a
+	// system crash or powerloss.
+	stderr := zapcore.Lock(AddNopSync(os.Stderr))
 	if options.JSON.SplitStream {
-		stdout := zapcore.Lock(os.Stdout)
+		stdout := zapcore.Lock(AddNopSync(os.Stdout))
 		size := options.JSON.InfoBufferSize.Value()
 		if size > 0 {
 			// Prevent integer overflow.
@@ -103,3 +112,16 @@ func (f Factory) Create(options config.FormatOptions) (logr.Logger, func()) {
 	// Write info messages and errors to stderr to prevent mixing with normal program output.
 	return NewJSONLogger(stderr, nil, nil)
 }
+
+// AddNoSync adds a NOP Sync implementation.
+func AddNopSync(writer io.Writer) zapcore.WriteSyncer {
+	return nopSync{Writer: writer}
+}
+
+type nopSync struct {
+	io.Writer
+}
+
+func (f nopSync) Sync() error {
+	return nil
+}
diff --git a/test/integration/logs/benchmark/benchmark_test.go b/test/integration/logs/benchmark/benchmark_test.go
index 2312a485c4c..e810e88f3a3 100644
--- a/test/integration/logs/benchmark/benchmark_test.go
+++ b/test/integration/logs/benchmark/benchmark_test.go
@@ -33,7 +33,6 @@ import (
 	"time"
 
 	"github.com/go-logr/logr"
-	"go.uber.org/zap/zapcore"
 	"k8s.io/component-base/logs"
 	logsjson "k8s.io/component-base/logs/json"
 	"k8s.io/klog/v2"
@@ -173,10 +172,11 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo
 			klog.SetOutput(out)
 			defer klog.SetOutput(&output)
 		}
-		generateOutput(b, config, out)
+		generateOutput(b, config, nil, out)
 	})
 	b.Run("JSON", func(b *testing.B) {
 		var logger logr.Logger
+		var flush func()
 		var out1, out2 *os.File
 		if !discard {
 			var err error
@@ -193,7 +193,7 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo
 		}
 		b.Run("single-stream", func(b *testing.B) {
 			if discard {
-				logger, _ = logsjson.NewJSONLogger(zapcore.AddSync(&output), nil, nil)
+				logger, flush = logsjson.NewJSONLogger(logsjson.AddNopSync(&output), nil, nil)
 			} else {
 				stderr := os.Stderr
 				os.Stderr = out1
@@ -201,16 +201,16 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo
 					os.Stderr = stderr
 				}()
 				options := logs.NewOptions()
-				logger, _ = logsjson.Factory{}.Create(options.Config.Options)
+				logger, flush = logsjson.Factory{}.Create(options.Config.Options)
 			}
 			klog.SetLogger(logger)
 			defer klog.ClearLogger()
-			generateOutput(b, config, out1)
+			generateOutput(b, config, flush, out1)
 		})
 
 		b.Run("split-stream", func(b *testing.B) {
 			if discard {
-				logger, _ = logsjson.NewJSONLogger(zapcore.AddSync(&output), zapcore.AddSync(&output), nil)
+				logger, flush = logsjson.NewJSONLogger(logsjson.AddNopSync(&output), logsjson.AddNopSync(&output), nil)
 			} else {
 				stdout, stderr := os.Stdout, os.Stderr
 				os.Stdout, os.Stderr = out1, out2
@@ -219,16 +219,16 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo
 				}()
 				options := logs.NewOptions()
 				options.Config.Options.JSON.SplitStream = true
-				logger, _ = logsjson.Factory{}.Create(options.Config.Options)
+				logger, flush = logsjson.Factory{}.Create(options.Config.Options)
 			}
 			klog.SetLogger(logger)
 			defer klog.ClearLogger()
-			generateOutput(b, config, out1, out2)
+			generateOutput(b, config, flush, out1, out2)
 		})
 	})
 }
 
-func generateOutput(b *testing.B, config loadGeneratorConfig, files ...*os.File) {
+func generateOutput(b *testing.B, config loadGeneratorConfig, flush func(), files ...*os.File) {
 	msg := strings.Repeat("X", config.messageLength)
 	err := errors.New("fail")
 	start := time.Now()
@@ -257,6 +257,9 @@ func generateOutput(b *testing.B, config loadGeneratorConfig, files ...*os.File)
 	}
 	wg.Wait()
 	klog.Flush()
+	if flush != nil {
+		flush()
+	}
 	b.StopTimer()
 
 	// Print some information about the result.