Open existing log files with O_APPEND at startup

klog shouldn't erase old log files when components restart,
and should also ensure it doesn't overwrite old logs in
existing files when restarts happen.

Previously, existing log files were opened with O_TRUNC at
both startup and rotation time. Now, existing files are
opened with O_APPEND at startup instead of O_TRUNC, but
still rotated with O_TRUNC.

klog.go

@@ -874,7 +874,7 @@ func (sb *syncBuffer) Sync() error {
 
 func (sb *syncBuffer) Write(p []byte) (n int, err error) {
 	if sb.nbytes+uint64(len(p)) >= MaxSize {
-		if err := sb.rotateFile(time.Now()); err != nil {
+		if err := sb.rotateFile(time.Now(), false); err != nil {
 			sb.logger.exit(err)
 		}
 	}
@@ -887,13 +887,15 @@ func (sb *syncBuffer) Write(p []byte) (n int, err error) {
 }
 
 // rotateFile closes the syncBuffer's file and starts a new one.
-func (sb *syncBuffer) rotateFile(now time.Time) error {
+// The startup argument indicates whether this is the initial startup of klog.
+// If startup is true, existing files are opened for apending instead of truncated.
+func (sb *syncBuffer) rotateFile(now time.Time, startup bool) error {
 	if sb.file != nil {
 		sb.Flush()
 		sb.file.Close()
 	}
 	var err error
-	sb.file, _, err = create(severityName[sb.sev], now)
+	sb.file, _, err = create(severityName[sb.sev], now, startup)
 	sb.nbytes = 0
 	if err != nil {
 		return err
@@ -928,7 +930,7 @@ func (l *loggingT) createFiles(sev severity) error {
 			logger: l,
 			sev:    s,
 		}
-		if err := sb.rotateFile(now); err != nil {
+		if err := sb.rotateFile(now, true); err != nil {
 			return err
 		}
 		l.file[s] = sb

klog_file.go

@@ -97,9 +97,11 @@ var onceLogDirs sync.Once
 // contains tag ("INFO", "FATAL", etc.) and t.  If the file is created
 // successfully, create also attempts to update the symlink for that tag, ignoring
 // errors.
-func create(tag string, t time.Time) (f *os.File, filename string, err error) {
+// The startup argument indicates whether this is the initial startup of klog.
+// If startup is true, existing files are opened for apending instead of truncated.
+func create(tag string, t time.Time, startup bool) (f *os.File, filename string, err error) {
 	if logging.logFile != "" {
-		f, err := os.Create(logging.logFile)
+		f, err := openOrCreate(logging.logFile, startup)
 		if err == nil {
 			return f, logging.logFile, nil
 		}
@@ -113,7 +115,7 @@ func create(tag string, t time.Time) (f *os.File, filename string, err error) {
 	var lastErr error
 	for _, dir := range logDirs {
 		fname := filepath.Join(dir, name)
-		f, err := os.Create(fname)
+		f, err := openOrCreate(fname, startup)
 		if err == nil {
 			symlink := filepath.Join(dir, link)
 			os.Remove(symlink)        // ignore err
@@ -124,3 +126,14 @@ func create(tag string, t time.Time) (f *os.File, filename string, err error) {
 	}
 	return nil, "", fmt.Errorf("log: cannot create log: %v", lastErr)
 }
+
+// The startup argument indicates whether this is the initial startup of klog.
+// If startup is true, existing files are opened for appending instead of truncated.
+func openOrCreate(name string, startup bool) (*os.File, error) {
+	if startup {
+		f, err := os.OpenFile(name, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666)
+		return f, err
+	}
+	f, err := os.Create(name)
+	return f, err
+}

klog_test.go

@@ -19,6 +19,7 @@ package klog
 import (
 	"bytes"
 	"fmt"
+	"io/ioutil"
 	stdLog "log"
 	"path/filepath"
 	"runtime"
@@ -28,6 +29,9 @@ import (
 	"time"
 )
 
+// TODO: This test package should be refactored so that tests cannot
+// interfere with each-other.
+
 // Test that shortHostname works as advertised.
 func TestShortHostname(t *testing.T) {
 	for hostname, expect := range map[string]string{
@@ -371,6 +375,76 @@ func TestRollover(t *testing.T) {
 	}
 }
 
+func TestOpenAppendOnStart(t *testing.T) {
+	const (
+		x string = "xxxxxxxxxx"
+		y string = "yyyyyyyyyy"
+	)
+
+	setFlags()
+	var err error
+	defer func(previous func(error)) { logExitFunc = previous }(logExitFunc)
+	logExitFunc = func(e error) {
+		err = e
+	}
+
+	f, err := ioutil.TempFile("", "test_klog_OpenAppendOnStart")
+	if err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+	logging.logFile = f.Name()
+
+	// Erase files created by prior tests,
+	for i := range logging.file {
+		logging.file[i] = nil
+	}
+
+	// Logging creates the file
+	Info(x)
+	_, ok := logging.file[infoLog].(*syncBuffer)
+	if !ok {
+		t.Fatal("info wasn't created")
+	}
+	if err != nil {
+		t.Fatalf("info has initial error: %v", err)
+	}
+	// ensure we wrote what we expected
+	logging.flushAll()
+	b, err := ioutil.ReadFile(logging.logFile)
+	if err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+	if !strings.Contains(string(b), x) {
+		t.Fatalf("got %s, missing expected Info log: %s", string(b), x)
+	}
+
+	// Set the file to nil so it gets "created" (opened) again on the next write.
+	for i := range logging.file {
+		logging.file[i] = nil
+	}
+
+	// Logging agagin should open the file again with O_APPEND instead of O_TRUNC
+	Info(y)
+	// ensure we wrote what we expected
+	logging.flushAll()
+	b, err = ioutil.ReadFile(logging.logFile)
+	if err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+	if !strings.Contains(string(b), y) {
+		t.Fatalf("got %s, missing expected Info log: %s", string(b), y)
+	}
+	// The initial log message should be preserved across create calls.
+	logging.flushAll()
+	b, err = ioutil.ReadFile(logging.logFile)
+	if err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+	if !strings.Contains(string(b), x) {
+		t.Fatalf("got %s, missing expected Info log: %s", string(b), x)
+	}
+}
+
 func TestLogBacktraceAt(t *testing.T) {
 	setFlags()
 	defer logging.swap(logging.newBuffers())