github.com/anth0d/nomad@v0.0.0-20221214183521-ae3a0a2cad06/client/logmon/logmon.go (about) 1 package logmon 2 3 import ( 4 "fmt" 5 "io" 6 "os" 7 "strings" 8 "sync" 9 "time" 10 11 hclog "github.com/hashicorp/go-hclog" 12 "github.com/hashicorp/nomad/client/lib/fifo" 13 "github.com/hashicorp/nomad/client/logmon/logging" 14 ) 15 16 const ( 17 // processOutputCloseTolerance is the length of time we will wait for the 18 // launched process to close its stdout/stderr before we force close it. If 19 // data is written after this tolerance, we will not capture it. 20 processOutputCloseTolerance = 2 * time.Second 21 ) 22 23 type LogConfig struct { 24 // LogDir is the host path where logs are to be written to 25 LogDir string 26 27 // StdoutLogFile is the path relative to LogDir for stdout logging 28 StdoutLogFile string 29 30 // StderrLogFile is the path relative to LogDir for stderr logging 31 StderrLogFile string 32 33 // StdoutFifo is the path on the host to the stdout pipe 34 StdoutFifo string 35 36 // StderrFifo is the path on the host to the stderr pipe 37 StderrFifo string 38 39 // MaxFiles is the max rotated files allowed 40 MaxFiles int 41 42 // MaxFileSizeMB is the max log file size in MB allowed before rotation occures 43 MaxFileSizeMB int 44 } 45 46 type LogMon interface { 47 Start(*LogConfig) error 48 Stop() error 49 } 50 51 func NewLogMon(logger hclog.Logger) LogMon { 52 return &logmonImpl{ 53 logger: logger, 54 } 55 } 56 57 type logmonImpl struct { 58 logger hclog.Logger 59 tl *TaskLogger 60 lock sync.Mutex 61 } 62 63 func (l *logmonImpl) Start(cfg *LogConfig) error { 64 l.lock.Lock() 65 defer l.lock.Unlock() 66 67 // first time Start has been called 68 if l.tl == nil { 69 return l.start(cfg) 70 } 71 72 // stdout and stderr have been closed, this happens during task restarts 73 // restart the TaskLogger 74 if !l.tl.IsRunning() { 75 l.tl.Close() 76 return l.start(cfg) 77 } 78 79 // if the TaskLogger has been created and is currently running, noop 80 return nil 81 } 82 83 func (l *logmonImpl) start(cfg *LogConfig) error { 84 tl, err := NewTaskLogger(cfg, l.logger) 85 if err != nil { 86 return err 87 } 88 l.tl = tl 89 return nil 90 } 91 92 func (l *logmonImpl) Stop() error { 93 l.lock.Lock() 94 defer l.lock.Unlock() 95 if l.tl != nil { 96 l.tl.Close() 97 } 98 return nil 99 } 100 101 type TaskLogger struct { 102 config *LogConfig 103 104 // rotator for stdout 105 lro *logRotatorWrapper 106 107 // rotator for stderr 108 lre *logRotatorWrapper 109 } 110 111 // IsRunning will return true as long as one rotator wrapper is still running 112 func (tl *TaskLogger) IsRunning() bool { 113 lroRunning := tl.lro != nil && tl.lro.isRunning() 114 lreRunning := tl.lre != nil && tl.lre.isRunning() 115 116 return lroRunning && lreRunning 117 } 118 119 func (tl *TaskLogger) Close() { 120 var wg sync.WaitGroup 121 if tl.lro != nil { 122 wg.Add(1) 123 go func() { 124 tl.lro.Close() 125 wg.Done() 126 }() 127 } 128 if tl.lre != nil { 129 wg.Add(1) 130 go func() { 131 tl.lre.Close() 132 wg.Done() 133 }() 134 } 135 wg.Wait() 136 } 137 138 func NewTaskLogger(cfg *LogConfig, logger hclog.Logger) (*TaskLogger, error) { 139 tl := &TaskLogger{config: cfg} 140 141 logFileSize := int64(cfg.MaxFileSizeMB * 1024 * 1024) 142 lro, err := logging.NewFileRotator(cfg.LogDir, cfg.StdoutLogFile, 143 cfg.MaxFiles, logFileSize, logger) 144 if err != nil { 145 return nil, fmt.Errorf("failed to create stdout logfile for %q: %v", cfg.StdoutLogFile, err) 146 } 147 148 wrapperOut, err := newLogRotatorWrapper(cfg.StdoutFifo, logger, lro) 149 if err != nil { 150 return nil, err 151 } 152 153 tl.lro = wrapperOut 154 155 lre, err := logging.NewFileRotator(cfg.LogDir, cfg.StderrLogFile, 156 cfg.MaxFiles, logFileSize, logger) 157 if err != nil { 158 return nil, fmt.Errorf("failed to create stderr logfile for %q: %v", cfg.StderrLogFile, err) 159 } 160 161 wrapperErr, err := newLogRotatorWrapper(cfg.StderrFifo, logger, lre) 162 if err != nil { 163 return nil, err 164 } 165 166 tl.lre = wrapperErr 167 168 return tl, nil 169 170 } 171 172 // logRotatorWrapper wraps our log rotator and exposes a pipe that can feed the 173 // log rotator data. The processOutWriter should be attached to the process and 174 // data will be copied from the reader to the rotator. 175 type logRotatorWrapper struct { 176 fifoPath string 177 rotatorWriter io.WriteCloser 178 hasFinishedCopied chan struct{} 179 logger hclog.Logger 180 181 processOutReader io.ReadCloser 182 openCompleted chan struct{} 183 } 184 185 // isRunning will return true until the reader is closed 186 func (l *logRotatorWrapper) isRunning() bool { 187 select { 188 case <-l.hasFinishedCopied: 189 return false 190 default: 191 return true 192 } 193 } 194 195 // newLogRotatorWrapper takes a rotator and returns a wrapper that has the 196 // processOutWriter to attach to the stdout or stderr of a process. 197 func newLogRotatorWrapper(path string, logger hclog.Logger, rotator io.WriteCloser) (*logRotatorWrapper, error) { 198 logger.Info("opening fifo", "path", path) 199 200 var openFn func() (io.ReadCloser, error) 201 var err error 202 203 _, serr := os.Stat(path) 204 if os.IsNotExist(serr) { 205 openFn, err = fifo.CreateAndRead(path) 206 } else { 207 openFn = func() (io.ReadCloser, error) { 208 return fifo.OpenReader(path) 209 } 210 } 211 212 if err != nil { 213 logger.Error("failed to create FIFO", "stat_error", serr, "create_err", err) 214 return nil, fmt.Errorf("failed to create fifo for extracting logs: %v", err) 215 } 216 217 wrap := &logRotatorWrapper{ 218 fifoPath: path, 219 rotatorWriter: rotator, 220 hasFinishedCopied: make(chan struct{}), 221 openCompleted: make(chan struct{}), 222 logger: logger, 223 } 224 225 wrap.start(openFn) 226 return wrap, nil 227 } 228 229 // start starts a goroutine that copies from the pipe into the rotator. This is 230 // called by the constructor and not the user of the wrapper. 231 func (l *logRotatorWrapper) start(openFn func() (io.ReadCloser, error)) { 232 go func() { 233 defer close(l.hasFinishedCopied) 234 235 reader, err := openFn() 236 if err != nil { 237 l.logger.Warn("failed to open fifo", "error", err) 238 return 239 } 240 l.processOutReader = reader 241 close(l.openCompleted) 242 243 _, err = io.Copy(l.rotatorWriter, reader) 244 if err != nil { 245 l.logger.Warn("failed to read from log fifo", "error", err) 246 // Close reader to propagate io error across pipe. 247 // Note that this may block until the process exits on 248 // Windows due to 249 // https://github.com/PowerShell/PowerShell/issues/4254 250 // or similar issues. Since this is already running in 251 // a goroutine its safe to block until the process is 252 // force-killed. 253 reader.Close() 254 } 255 }() 256 } 257 258 // Close closes the rotator and the process writer to ensure that the Wait 259 // command exits. 260 func (l *logRotatorWrapper) Close() { 261 // Wait up to the close tolerance before we force close 262 select { 263 case <-l.hasFinishedCopied: 264 case <-time.After(processOutputCloseTolerance): 265 } 266 267 // Closing the read side of a pipe may block on Windows if the process 268 // is being debugged as in: 269 // https://github.com/PowerShell/PowerShell/issues/4254 270 // The pipe will be closed and cleaned up when the process exits. 271 closeDone := make(chan struct{}) 272 go func() { 273 defer close(closeDone) 274 275 // we must wait until reader is opened before we can close it, and cannot inteerrupt an in-flight open request 276 // The Close function uses processOutputCloseTolerance to protect against long running open called 277 // and then request will be interrupted and file will be closed on process shutdown 278 <-l.openCompleted 279 280 if l.processOutReader != nil { 281 err := l.processOutReader.Close() 282 if err != nil && !strings.Contains(err.Error(), "file already closed") { 283 l.logger.Warn("error closing read-side of process output pipe", "error", err) 284 } 285 } 286 287 }() 288 289 select { 290 case <-closeDone: 291 case <-time.After(processOutputCloseTolerance): 292 l.logger.Warn("timed out waiting for read-side of process output pipe to close") 293 } 294 295 l.rotatorWriter.Close() 296 }