Go服务：goroutine捕获Stderr并重定向到Stdout的问题排查

问题描述 #

需要编写一个调用黑盒函数的Go服务，拦截该函数输出到Stderr的错误信息并立即打印。以下是初始实现代码：

package main

import (
    "bytes"
    "fmt"
    "io"
    "os"
)

func doMagic(i int) {
    fmt.Fprintf(os.Stderr, "%d stderr\n", i)
}

func main() {
    ch := make(chan struct{})
    var buf bytes.Buffer
    var wr, r *os.File
    i := 0
    go func() {
        for {
            ch <- struct{}{}
            i += 1

            doMagic(i)

            wr.Close()
            size, _ := io.Copy(&buf, r)
            if size != 0 {
                fmt.Printf("Size: %d, Content: %s", size, buf.String())
            } else {
                fmt.Println("Empty")
            }
        }
    }()
    for {
        r, wr, _ = os.Pipe()
        os.Stderr = wr
        <-ch
    }
}

运行后发现不符合预期：goroutine第一次循环本该输出doMagic生成的第一条错误信息，却打印了“Empty”。同时需要解决如何实时打印错误信息、避免每次循环创建新Pipe并关闭写通道的问题。

更新（2024-03-19）
读取缓冲区后需要重置，避免旧数据残留：

...
        size, _ := io.Copy(&buf, r)
        if size != 0 {
            fmt.Printf("Size: %d, Content: %s", size, buf.String())
        } else {
            fmt.Println("Empty")
        }
        buf.Reset()  // 重置缓冲区
...

首次输出Empty的原因 #

核心是goroutine间的同步顺序错误：

1. 子goroutine先执行ch <- struct{}{}，向主goroutine发送信号
2. 此时主goroutine还没完成os.Stderr = wr的设置，doMagic(i)调用时使用的是系统默认的Stderr，而非新创建的Pipe写端
3. 当主goroutine完成Pipe创建和Stderr赋值后，子goroutine已经执行完doMagic，Pipe的读端没有任何数据，因此输出“Empty”

修复首次Empty问题 #

调整同步顺序，让子goroutine等待主goroutine完成Stderr的替换后，再执行doMagic：

package main

import (
    "bytes"
    "fmt"
    "io"
    "os"
)

func doMagic(i int) {
    fmt.Fprintf(os.Stderr, "%d stderr\n", i)
}

func main() {
    ch := make(chan struct{})
    var buf bytes.Buffer
    var wr, r *os.File
    i := 0
    go func() {
        for {
            <-ch // 等待主goroutine设置好Stderr
            i += 1

            doMagic(i)

            wr.Close()
            size, _ := io.Copy(&buf, r)
            if size != 0 {
                fmt.Printf("Size: %d, Content: %s", size, buf.String())
            } else {
                fmt.Println("Empty")
            }
            buf.Reset() // 重置缓冲区，避免下次读取混入旧数据
        }
    }()
    for {
        r, wr, _ = os.Pipe()
        os.Stderr = wr
        ch <- struct{}{} // 通知子goroutine可以执行doMagic了
    }
}

实现实时打印错误信息 #

原代码需要关闭Pipe写端才能触发读取，无法做到实时打印。可以改为持续监听Pipe读端：启动一个goroutine不断从Pipe读端读取数据，一旦有内容就立即打印，无需关闭写端。

避免重复创建Pipe的优化方案 #

不需要每次循环创建新Pipe，只需初始化一次Pipe并替换Stderr，然后用常驻goroutine处理读端数据：

package main

import (
    "fmt"
    "io"
    "os"
)

func doMagic(i int) {
    fmt.Fprintf(os.Stderr, "%d stderr\n", i)
}

func main() {
    // 只创建一次Pipe
    r, wr, err := os.Pipe()
    if err != nil {
        panic(err)
    }
    defer wr.Close()
    defer r.Close()

    // 替换系统Stderr
    oldStderr := os.Stderr
    os.Stderr = wr
    defer func() { os.Stderr = oldStderr }() // 程序退出时恢复原Stderr

    // 启动常驻goroutine实时读取并打印
    go func() {
        _, err := io.Copy(os.Stdout, r) // 直接将Pipe读端的数据复制到Stdout，实现实时打印
        if err != nil && err != io.EOF {
            fmt.Fprintf(oldStderr, "读取Stderr拦截数据失败: %v\n", err)
        }
    }()

    // 模拟调用黑盒函数
    i := 0
    for {
        i += 1
        doMagic(i)
        // 这里可以根据需求添加延迟或退出条件
        // time.Sleep(time.Second)
        // if i >= 5 { break }
    }
}

这个方案的优势：

• 无需重复创建/关闭Pipe，减少系统资源开销
• 实时输出doMagic写入Stderr的内容，无需等待写端关闭
• 程序退出时恢复原Stderr，避免影响其他逻辑

内容的提问来源于stack exchange，提问作者Andriy