compiler_wrapper: fix write() races

If we make this function write its data atomically to the RUSAGE file,
we can have all compilations log to this file, which would allow us to
trivially log all of the build info for a given tryjob.

BUG=chromium:1054897
TEST=nocturne-llvm-next-toolchain-tryjob. Local --nousepkg
build_packages produced a file with 0 torn lines.

Change-Id: Ic6b014af11e812111fa21a56133bbe1b6b31f954
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/toolchain-utils/+/2066710
Reviewed-by: Manoj Gupta <manojgupta@chromium.org>
Commit-Queue: George Burgess <gbiv@chromium.org>
Tested-by: George Burgess <gbiv@chromium.org>

1 files changed, 43 insertions, 9 deletions

diff --git a/compiler_wrapper/rusage_flag.go b/compiler_wrapper/rusage_flag.go
index 2a3768c1..690308b2 100644
--- a/compiler_wrapper/rusage_flag.go
+++ b/compiler_wrapper/rusage_flag.go
@@ -18,6 +18,26 @@ func getRusageLogFilename(env env) string {
 	return value
 }
 
+func lockFileExclusive(fd uintptr) error {
+	maxTries := 100
+	for i := 0; i < maxTries; i++ {
+		const seekSet = 0
+		err := syscall.FcntlFlock(fd, syscall.F_SETLKW, &syscall.Flock_t{
+			Type:   syscall.F_WRLCK,
+			Whence: seekSet,
+			Start:  0,
+			Len:    0,
+		})
+		if err == nil {
+			return nil
+		}
+		if err != syscall.EINTR {
+			return fmt.Errorf("locking file: %v", err)
+		}
+	}
+	return fmt.Errorf("locking file failed after %d tries", maxTries)
+}
+
 func logRusage(env env, logFileName string, compilerCmd *command) (exitCode int, err error) {
 	rusageBefore := syscall.Rusage{}
 	if err := syscall.Getrusage(syscall.RUSAGE_CHILDREN, &rusageBefore); err != nil {
@@ -49,21 +69,35 @@ func logRusage(env env, logFileName string, compilerCmd *command) (exitCode int,
 	if err := os.MkdirAll(filepath.Dir(logFileName), 0777); err != nil {
 		return 0, wrapErrorwithSourceLocf(err, "error creating rusage log directory %s", logFileName)
 	}
+
+	timeUnit := float64(time.Second)
+	data := fmt.Sprintf("%.5f : %.5f : %.5f : %d : %s : %s\n",
+		float64(elapsedRealTime)/timeUnit, float64(elapsedUserTime)/timeUnit, float64(elapsedSysTime)/timeUnit,
+		maxMemUsed, absCompilerPath,
+		strings.Join(append([]string{filepath.Base(absCompilerPath)}, compilerCmd.Args...), " "))
+
 	// Note: using file mode 0666 so that a root-created log is writable by others.
 	logFile, err := os.OpenFile(logFileName, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0666)
 	if err != nil {
-		return 0, wrapErrorwithSourceLocf(err, "error creating rusage logfile %s", logFileName)
+		return 0, wrapErrorwithSourceLocf(err, "creating rusage logfile %s", logFileName)
 	}
-	timeUnit := float64(time.Second)
-	if _, err := fmt.Fprintf(logFile, "%.5f : %.5f : %.5f : %d : %s : %s\n",
-		float64(elapsedRealTime)/timeUnit, float64(elapsedUserTime)/timeUnit, float64(elapsedSysTime)/timeUnit,
-		maxMemUsed, absCompilerPath,
-		strings.Join(append([]string{filepath.Base(absCompilerPath)}, compilerCmd.Args...), " ")); err != nil {
+
+	// O_APPEND's atomicity guarantees are only for writes up to a certain size. If we don't
+	// lock the file, we might end up with corrupted records.
+	//
+	// Note that Close()'ing the file releases all associated locks.
+	if err := lockFileExclusive(logFile.Fd()); err != nil {
 		_ = logFile.Close()
-		return 0, wrapErrorwithSourceLocf(err, "error writing rusage logfile %s", logFileName)
+		return 0, wrapErrorwithSourceLocf(err, "locking rusage logfile %s: %v", logFileName, err)
+	}
+
+	_, err = logFile.WriteString(data)
+	closeErr := logFile.Close()
+	if err != nil {
+		return 0, wrapErrorwithSourceLocf(err, "writing to rusage logfile %s: %v", logFileName, err)
 	}
-	if err := logFile.Close(); err != nil {
-		return 0, wrapErrorwithSourceLocf(err, "error closing rusage logfile %s", logFileName)
+	if closeErr != nil {
+		return 0, wrapErrorwithSourceLocf(err, "closing rusage logfile %s: %v", logFileName, closeErr)
 	}
 
 	return exitCode, nil