1// Copyright 2019 The ChromiumOS Authors 2// Use of this source code is governed by a BSD-style license that can be 3// found in the LICENSE file. 4 5package main 6 7import ( 8 "encoding/json" 9 "fmt" 10 "os" 11 "path/filepath" 12 "syscall" 13 "time" 14) 15 16func getRusageLogFilename(env env) string { 17 value, _ := env.getenv("TOOLCHAIN_RUSAGE_OUTPUT") 18 return value 19} 20 21func isRusageEnabled(env env) bool { 22 return getRusageLogFilename(env) != "" 23} 24 25func lockFileExclusive(fd uintptr) error { 26 maxTries := 100 27 for i := 0; i < maxTries; i++ { 28 const seekSet = 0 29 err := syscall.FcntlFlock(fd, syscall.F_SETLKW, &syscall.Flock_t{ 30 Type: syscall.F_WRLCK, 31 Whence: seekSet, 32 Start: 0, 33 Len: 0, 34 }) 35 if err == nil { 36 return nil 37 } 38 if err != syscall.EINTR { 39 return fmt.Errorf("locking file: %v", err) 40 } 41 } 42 return fmt.Errorf("locking file failed after %d tries", maxTries) 43} 44 45type rusageLog struct { 46 ExitCode int `json:"exit_code"` 47 ElapsedRealTime float64 `json:"elapsed_real_time"` 48 ElapsedUserTime float64 `json:"elapsed_user_time"` 49 ElapsedSysTime float64 `json:"elapsed_sys_time"` 50 MaxMemUsed int64 `json:"max_mem_used"` 51 Compiler string `json:"compiler"` 52 CompilerArgs []string `json:"compiler_args"` 53 WorkingDirectory string `json:"working_directory"` 54} 55 56func removeRusageFromCommand(compilerCmd *command) *command { 57 return &command{ 58 Path: compilerCmd.Path, 59 Args: compilerCmd.Args, 60 EnvUpdates: append(compilerCmd.EnvUpdates, "TOOLCHAIN_RUSAGE_OUTPUT="), 61 } 62} 63 64// maybeCaptureRusage captures rusage for execution of action() 65// unless action returns an error or logFileName is "" 66// a function is returned which saves the rusage log data at logFileName unless logFileName is "" 67// an error is returned if action returns an error, or rusage commands in syscall fails 68func maybeCaptureRusage(env env, compilerCmd *command, action func(willLogRusage bool) error) (maybeCommitToFile func(exitCode int) error, err error) { 69 logFileName := getRusageLogFilename(env) 70 willLogRusage := isRusageEnabled(env) 71 if !willLogRusage { 72 if err := action(willLogRusage); err != nil { 73 return nil, err 74 } 75 return func(int) error { return nil }, nil 76 } 77 78 rusageBefore := syscall.Rusage{} 79 if err := syscall.Getrusage(syscall.RUSAGE_CHILDREN, &rusageBefore); err != nil { 80 return nil, fmt.Errorf("getting initial rusage: %v", err) 81 } 82 startTime := time.Now() 83 84 if err := action(willLogRusage); err != nil { 85 return nil, err 86 } 87 88 elapsedRealTime := time.Since(startTime) 89 rusageAfter := syscall.Rusage{} 90 if err := syscall.Getrusage(syscall.RUSAGE_CHILDREN, &rusageAfter); err != nil { 91 return nil, fmt.Errorf("getting final rusage: %v", err) 92 } 93 94 return func(exitCode int) error { 95 elapsedSysTime := time.Duration(rusageAfter.Stime.Nano()-rusageBefore.Stime.Nano()) * time.Nanosecond 96 elapsedUserTime := time.Duration(rusageAfter.Utime.Nano()-rusageBefore.Utime.Nano()) * time.Nanosecond 97 // Note: We assume that the compiler takes more heap than any other 98 // subcommands that we might have executed before. 99 maxMemUsed := rusageAfter.Maxrss 100 absCompilerPath := getAbsCmdPath(env, compilerCmd) 101 102 // We need to temporarily set umask to 0 to ensure 777 permissions are actually 777 103 // This effects builderbots in particular 104 oldMask := env.umask(0) 105 defer env.umask(oldMask) 106 107 // We want to know what package is being compiled. The working directory gives us a good clue. 108 cwd, err := os.Getwd() 109 if err != nil { 110 return wrapErrorwithSourceLocf(err, "error getting working directory for rusage log") 111 } 112 113 if err := os.MkdirAll(filepath.Dir(logFileName), 0777); err != nil { 114 return wrapErrorwithSourceLocf(err, "error creating rusage log directory %s", logFileName) 115 } 116 117 timeUnit := float64(time.Second) 118 119 logEntry := rusageLog{ 120 ExitCode: exitCode, 121 ElapsedRealTime: float64(elapsedRealTime) / timeUnit, 122 ElapsedUserTime: float64(elapsedUserTime) / timeUnit, 123 ElapsedSysTime: float64(elapsedSysTime) / timeUnit, 124 MaxMemUsed: maxMemUsed, 125 Compiler: absCompilerPath, 126 CompilerArgs: compilerCmd.Args, 127 WorkingDirectory: cwd, 128 } 129 130 // Note: using file mode 0666 so that a root-created log is writable by others. 131 logFile, err := os.OpenFile(logFileName, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0666) 132 if err != nil { 133 return wrapErrorwithSourceLocf(err, "creating rusage logfile %s", logFileName) 134 } 135 136 // O_APPEND's atomicity guarantees are only for writes up to a certain size. If we don't 137 // lock the file, we might end up with corrupted records. 138 // 139 // Note that Close()'ing the file releases all associated locks. 140 if err := lockFileExclusive(logFile.Fd()); err != nil { 141 _ = logFile.Close() 142 return wrapErrorwithSourceLocf(err, "locking rusage logfile %s: %v", logFileName, err) 143 } 144 145 if err := json.NewEncoder(logFile).Encode(logEntry); err != nil { 146 _ = logFile.Close() 147 return wrapErrorwithSourceLocf(err, "converting rusage logfile entry to JSON %v", logEntry) 148 } 149 150 closeErr := logFile.Close() 151 if err != nil { 152 return wrapErrorwithSourceLocf(err, "writing to rusage logfile %s: %v", logFileName, err) 153 } 154 if closeErr != nil { 155 return wrapErrorwithSourceLocf(err, "closing rusage logfile %s: %v", logFileName, closeErr) 156 } 157 158 return nil 159 }, nil 160} 161