Надежно захватить вывод внешней команды

Question

Мне нужно вызвать множество кратковременных (а иногда и долгоживущих) внешних процессов в быстрой последовательности и обрабатывать stdout и stderr в реальном времени. Я нашел множество решений для этого, используя StdoutPipe и StderrPipe с bufio.Scanner для каждого, упакованные в горутины. Это работает большую часть времени, но время от времени проглатывает вывод внешней команды, и я не могу понять, почему.

Вот минимальный пример, показывающий такое поведение на MacOS X (Mojave) и на Linux:

package main

import (
    "bufio"
    "log"
    "os/exec"
    "sync"
)

func main() {
    for i := 0; i < 50000; i++ {
        log.Println("Loop")

        var wg sync.WaitGroup

        cmd := exec.Command("echo", "1")
        stdout, err := cmd.StdoutPipe()
        if err != nil {
            panic(err)
        }

        cmd.Start()

        stdoutScanner := bufio.NewScanner(stdout)
        stdoutScanner.Split(bufio.ScanLines)

        wg.Add(1)
        go func() {
            for stdoutScanner.Scan() {
                line := stdoutScanner.Text()
                log.Printf("[stdout] %s\n", line)
            }
            wg.Done()
        }()

        cmd.Wait()
        wg.Wait()
    }
}

Я пропустил обработку stderr для этого. При выполнении этого я получаю только около 49 900 [stdout] 1 строк (фактическое число меняется с каждым прогоном), хотя должно быть 50 000. Я вижу 50 000 loop строк, поэтому, похоже, преждевременно d ie. Это где-то пахнет как состояние гонки, но я не могу понять, где.

Это прекрасно работает, если я не помещаю сканирование l oop в программу, но тогда я теряю способность одновременно прочитайте stderr, что мне нужно.

Я пытался запустить это с -race, Go сообщает об отсутствии гонок данных.

У меня нет идей, что я Я ошибаюсь?

Answer 1

Вы не проверяете ошибки в нескольких местах.

В некоторых случаях это на самом деле не вызывает проблем, но все же стоит проверить:

cmd.Start()

может вернуться ошибка, в этом случае команда никогда не выполнялась. (Это не настоящая проблема.)

Когда stdoutScanner.Scan() возвращает false, stdoutScanner.Err() может показывать ошибку. Если вы начнете проверять это, вы обнаружите некоторые ошибки:

2020/02/19 15:38:17 [stdout err] read |0: file already closed

Это не настоящая проблема, но - ага - это соответствует симптомам, которые вы видите: не все результаты были замечены. Теперь, почему чтение stdout утверждает, что файл закрыт? Ну, откуда взялась stdout? Отсюда:

stdout, err := cmd.StdoutPipe()

Взгляните на исходный код для этой функции , который заканчивается следующими строками:

c.closeAfterStart = append(c.closeAfterStart, pw)
c.closeAfterWait = append(c.closeAfterWait, pr)
return pr, nil

(и pr возвращаемое значение для чтения канала). Хм: что может значить closeAfterWait?

Теперь, вот ваши последние две строки в вашем l oop:

cmd.Wait()
wg.Wait()

То есть сначала мы ждем, пока cmd Фини sh. (Когда cmd заканчивается, что закрывается?) Затем мы ждем goroutine, который читает стандартный вывод cmd в fini sh. (Хм, а что еще можно читать из pr канала?)

Исправление теперь очевидно: поменяйте местами wg.Wait(), который ждет, пока потребитель канала stdout завершит чтение sh с cmd.Wait(), который ожидает выхода echo ... и затем закрывает конец чтения канала. Если вы закроете, пока читатели все еще читают, они могут никогда не прочитать то, что вы ожидали.