'go test'打印FAIL,但没有明显的测试失败或失败原因的指示

mm9b1k5b  于 2023-02-01  发布在  Go
关注(0)|答案(3)|浏览(294)

我已经看到过这种情况以多种不同的方式发生,但通常测试输出的结尾类似于

...
        --- PASS: TestVariousQueries/7-node/34-G (8.50s)
FAIL
FAIL    github.com/pilosa/pilosa/v2 483.327s
FAIL

在我们的特定案例中,我们有很多使用t.Run的嵌套子测试,以及并行运行的测试,但是一般来说,我们发现测试套件有可能失败,而单个测试没有失败。
在我上面例子中,如果向后搜索“FAIL”,您看起来像这样:

--- FAIL: TestVariousQueries/7-node (482.60s)
        --- PASS: TestVariousQueries/7-node/0-G
...

在这里,它表明顶层测试失败了,但是所有的子测试似乎都通过了,并且没有其他输出或消息表明测试失败的原因。
有时候它看起来像这样,这给了我们更多的线索

...
=== RUN   TestVariousQueries/7-node/8-Count(All())
FAIL    github.com/pilosa/pilosa/v2 394.988s
FAIL

在这种情况下,最后一个测试似乎开始了,但不知何故失败了,没有输出(我们希望得到一个--- FAIL行的特定测试,而不仅仅是包级失败。
什么情况下会导致这种情况发生?如何调试?

vcudknz3

vcudknz31#

哪些情况会导致这种情况发生?
您是否正在使用t.Fail()(或t.FailNow())?在子测试之外调用t.Fail()将重现您所观察到的情况:所有子测试均通过,但整体测试失败,无输出。示例https://go.dev/play/p/oOeQ_migV1l

func TestVariousQueries(t *testing.T) {
    t.Run("7-node", func(t *testing.T) {
        t.Run("0-G", func(t *testing.T) { return })
        t.Run("1-G", func(t *testing.T) { return })
        t.Run("2-G", func(t *testing.T) { return })
        t.Run("3-G", func(t *testing.T) { return })
        if true {
            t.Fail()
        }
    })
}
--- FAIL: TestVariousQueries (0.00s)
    --- FAIL: TestVariousQueries/7-node (0.00s)
        --- PASS: TestVariousQueries/7-node/0-G (0.00s)
        --- PASS: TestVariousQueries/7-node/1-G (0.00s)
        --- PASS: TestVariousQueries/7-node/2-G (0.00s)
        --- PASS: TestVariousQueries/7-node/3-G (0.00s)
FAIL
vptzau2j

vptzau2j2#

我不确定是什么原因导致了这种情况,但我确实看到了当系统内存不足时,OOM killer会终止测试进程。在Linux上,至少您可以在测试运行时运行dmesg或类似tail -f /var/log/syslog的命令来查看内核日志。如果您看到类似以下内容:

[58234.350712] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/user.slice/user-1000.slice/session-12.scope,task=pilosa.test,pid=62637,uid=1000
[58234.351191] Out of memory: Killed process 62637 (pilosa.test) total-vm:178386044kB, anon-rss:15656564kB, file-rss:0kB, shmem-rss:0kB, UID:1000 pgtables:63880kB oom_score_adj:0
[58235.243972] oom_reaper: reaped process 62637 (pilosa.test), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

您可以相当肯定地说,测试是由于内存不足而被终止的。
另一种可能的情况是,测试中(或被测试中)的某个代码调用了os.Exit,在这种情况下,根据Go语言的版本和操作系统,你可能会看到一个状态码,或者你可能只看到FAIL消息,就像最初问题中的例子一样。
一般来说,如果您在测试中看到这样的输出,那么很有可能是由于某种原因导致测试进程退出,从而导致测试运行程序(go test)打印FAIL行,而不告诉您哪个测试失败了。

0yycz8jy

0yycz8jy3#

如果其他人在这个问题上犯了错误-请务必注意您的进程内存使用情况。我将以下日志注入到我的测试中,从未看到超过100 MB的增长-这让我感到困惑。然后我运行linux/unix命令“top”并按内存排序(Shift M)-我的进程攀升到4 GB!

func bToMb(b uint64) uint64 {
    return b / 1024 / 1024
}
func PrintMemUsage(text string) {
    var m runtime.MemStats
    runtime.ReadMemStats(&m)
    fmt.Printf("%v: ", text)
    fmt.Printf("HeapAlloc = %v MB", bToMb(m.HeapAlloc))
    fmt.Printf(" HeapInuse = %v MB", bToMb(m.HeapInuse))
    fmt.Printf(" HeapIdle = %v MB", bToMb(m.HeapIdle))
    fmt.Printf(" HeapReleased = %v MB", bToMb(m.HeapReleased))
    fmt.Printf(" HeapSys = %v MB", bToMb(m.HeapSys))
    fmt.Printf(" Alloc = %v MB", bToMb(m.Alloc))
    fmt.Printf(" TotalAlloc = %v MB", bToMb(m.TotalAlloc))
    fmt.Printf(" Sys = %v MB", bToMb(m.Sys))
    fmt.Printf(" NumGC = %v\n", m.NumGC)
}

上面的日志没有准确地显示我的进程正在使用的内存(6 GB对30 MB)。
我想知道,如果我的进程超过了某个阈值,是否可以触发下面的一个或两个。但是,由于我似乎不知道我的进程使用了多少内存(至少使用Go语言内部的MemStats),所以我不确定这对任何人是否有用:

runtime.GC()
debug.FreeOSMemory()

我知道以下页面:https://golang.org/pkg/runtime/#MemStats
但是,30 MB对6 GB的差异似乎很奇怪。经过更多的调试,我使用的Go包正在执行C/C++不安全的alloc/free -不确定是否有一种方法可以使用Go mem统计来跟踪这些分配?在这一点上-我可能需要调用一个操作系统命令来让操作系统告诉我我的进程占用了多少内存。
这篇文章似乎有一些很好的信息/答案:How to analyze golang memory?
这个软件包看起来是比调用操作系统命令更好的解决方案:https://github.com/pbnjay/memory

相关问题