В Go я пытаюсь:
- запустить подпроцесс
- читать из stdout и stderr отдельно
- реализовать общее время ожидания
После долгих поисков мы придумали некоторый код, который, кажется, выполняет свою работу большую часть времени.Но, похоже, существует условие гонки, при котором некоторые выходные данные не читаются.
Эта проблема возникает только в Linux, а не в Windows.
Следуя простейшему решению, найденному в Google, мы попыталисьсоздание контекста с таймаутом:
context.WithTimeout(context.Background(), 10*time.Second)
Хотя это работало большую часть времени, мы смогли найти случаи, когда он просто зависал навсегда.Был некоторый аспект дочернего процесса, который вызвал это в тупик.(Что-то связанное с внуками, которые не были достаточно отделены от дочернего процесса и, таким образом, приводили к тому, что ребенок никогда полностью не выходил.)
Кроме того, казалось, что в некоторых случаях error, который возвращается, когдаПри возникновении тайм-аута указывается тайм-аут, но он будет доставлен только после фактического выхода из процесса (что делает всю концепцию тайм-аута бесполезной).
func GetOutputsWithTimeout(command string, args []string, timeout int) (io.ReadCloser, io.ReadCloser, int, error) {
start := time.Now()
procLogger.Tracef("Initializing %s %+v", command, args)
cmd := exec.Command(command, args...)
// get pipes to standard output/error
stdout, err := cmd.StdoutPipe()
if err != nil {
return emptyReader(), emptyReader(), -1, fmt.Errorf("cmd.StdoutPipe() error: %+v", err.Error())
}
stderr, err := cmd.StderrPipe()
if err != nil {
return emptyReader(), emptyReader(), -1, fmt.Errorf("cmd.StderrPipe() error: %+v", err.Error())
}
// setup buffers to capture standard output and standard error
var buf bytes.Buffer
var ebuf bytes.Buffer
// create a channel to capture any errors from wait
done := make(chan error)
// create a semaphore to indicate when both pipes are closed
var wg sync.WaitGroup
wg.Add(2)
go func() {
if _, err := buf.ReadFrom(stdout); err != nil {
procLogger.Debugf("%s: Error Slurping stdout: %+v", command, err)
}
wg.Done()
}()
go func() {
if _, err := ebuf.ReadFrom(stderr); err != nil {
procLogger.Debugf("%s: Error Slurping stderr: %+v", command, err)
}
wg.Done()
}()
// start process
procLogger.Debugf("Starting %s", command)
if err := cmd.Start(); err != nil {
procLogger.Errorf("%s: failed to start: %+v", command, err)
return emptyReader(), emptyReader(), -1, fmt.Errorf("cmd.Start() error: %+v", err.Error())
}
go func() {
procLogger.Debugf("Waiting for %s (%d) to finish", command, cmd.Process.Pid)
err := cmd.Wait() // this can be 'forced' by the killing of the process
procLogger.Tracef("%s finished: errStatus=%+v", command, err) // err could be nil here
//notify select of completion, and the status
done <- err
}()
// Wait for timeout or completion.
select {
// Timed out
case <-time.After(time.Duration(timeout) * time.Second):
elapsed := time.Since(start)
procLogger.Errorf("%s: timeout after %.1f\n", command, elapsed.Seconds())
if err := TerminateTree(cmd); err != nil {
return ioutil.NopCloser(&buf), ioutil.NopCloser(&ebuf), -1,
fmt.Errorf("failed to kill %s, pid=%d: %+v",
command, cmd.Process.Pid, err)
}
wg.Wait() // this *should* take care of waiting for stdout and stderr to be collected after we killed the process
return ioutil.NopCloser(&buf), ioutil.NopCloser(&ebuf), -1,
fmt.Errorf("%s: timeout %d s reached, pid=%d process killed",
command, timeout, cmd.Process.Pid)
//Exited normally or with a non-zero exit code
case err := <-done:
wg.Wait() // this *should* take care of waiting for stdout and stderr to be collected after the process terminated naturally.
elapsed := time.Since(start)
procLogger.Tracef("%s: Done after %.1f\n", command, elapsed.Seconds())
rc := -1
// Note that we have to use go1.10 compatible mechanism.
if err != nil {
procLogger.Tracef("%s exited with error: %+v", command, err)
exitErr, ok := err.(*exec.ExitError)
if ok {
ws := exitErr.Sys().(syscall.WaitStatus)
rc = ws.ExitStatus()
}
procLogger.Debugf("%s exited with status %d", command, rc)
return ioutil.NopCloser(&buf), ioutil.NopCloser(&ebuf), rc,
fmt.Errorf("%s: process done with error: %+v",
command, err)
} else {
ws := cmd.ProcessState.Sys().(syscall.WaitStatus)
rc = ws.ExitStatus()
}
procLogger.Debugf("%s exited with status %d", command, rc)
return ioutil.NopCloser(&buf), ioutil.NopCloser(&ebuf), rc, nil
}
//NOTREACHED: should not reach this line!
}
Вызов GetOutputsWithTimeout("uname",[]string{"-mpi"},10) вызоветвозвращает ожидаемую единственную строку вывода большую часть времени .Но иногда он возвращает без вывода , как если бы процедура, которая читает stdout, не запустилась достаточно быстро, чтобы "перехватить" весь вывод (или завершиться рано?). "Большую часть времени" настоятельно рекомендуетусловие гонки.
Мы также иногда будем видеть ошибки из подпрограмм по поводу "файл уже закрыт" (это, кажется, происходит с условием тайм-аута, но также происходит и в другие "нормальные" времена).
Я бы подумал, что запуск goroutines до cmd.Start() гарантировал бы, что ни один вывод не будет пропущен, и что использование WaitGroup гарантирует, что они оба завершат работу перед чтением буферов.
Так как же нам не хватает вывода?Есть ли еще состояние гонки между двумя "читательскими" программами и cmd.Start()?Должны ли мы убедиться, что эти два работают с использованием еще одного WaitGroup?
Или есть проблема с реализацией ReadFrom()?
Обратите внимание, что в настоящее время мы используем go1.10 из-запроблемы обратной совместимости со старыми операционными системами, но тот же эффект возникает в go1.12.4.
Или мы переосмысливаем это, и простая реализация с context.WithTimeout() сделает эту работу?