gleak tests failing on Windows 10 with go1.19

[davidhsingyuchen]

Summary

This issue is created out of this issue comment.

System information:

• Go version: go1.19 windows/amd64
• OS: Windows 10 with version 10.0.19043 N/A Build 19043 (obtained by systeminfo)

Test Output

David@David-Dell MINGW64 /d/main/dev/onsi/gomega (master)
$ git rev-parse HEAD
40d7efe5027585fef7432815653ed2a9d0d9bc6e

David@David-Dell MINGW64 /d/main/dev/onsi/gomega (master)
$ ginkgo -r -p
[1661410384] Format Suite - 53/53 specs - 11 procs +++++++++++++++++++++++++++++++++++++++++++++++++++++ SUCCESS! 855.6998ms
[1661410384] Gbytes Suite - 39/39 specs - 11 procs +++++++++++++++++++++++++++++++++++++++ SUCCESS! 341.838ms
[1661410384] Gexec Suite - 25/25 specs - 11 procs
------------------------------
+ [SLOW TEST] [7.531 seconds]
.BuildWithEnvironment returns the environment to a good state
D:/main/dev/onsi/gomega/gexec/build_test.go:82
------------------------------
+ [SLOW TEST] [8.013 seconds]
.CompileTestWithEnvironment compiles the specified test package with the specified env vars
D:/main/dev/onsi/gomega/gexec/build_test.go:212
------------------------------
+ [SLOW TEST] [8.003 seconds]
.CompileTestWithEnvironment returns the environment to a good state
D:/main/dev/onsi/gomega/gexec/build_test.go:218
------------------------------
+ [SLOW TEST] [8.902 seconds]
.BuildWithEnvironment compiles the specified package with the specified env vars
D:/main/dev/onsi/gomega/gexec/build_test.go:76
------------------------------
+ [SLOW TEST] [9.240 seconds]
.BuildIn resets GOPATH to its original value
D:/main/dev/onsi/gomega/gexec/build_test.go:126
------------------------------
+ [SLOW TEST] [9.525 seconds]
.BuildIn appends the gopath env var
D:/main/dev/onsi/gomega/gexec/build_test.go:120
------------------------------
+
------------------------------
+ [SLOW TEST] [11.157 seconds]
ExitMatcher when passed something that is not an Exiter should error
D:/main/dev/onsi/gomega/gexec/exit_matcher_test.go:43
------------------------------
+ [SLOW TEST] [11.193 seconds]
ExitMatcher when passed something that is an Exiter should act normally
D:/main/dev/onsi/gomega/gexec/exit_matcher_test.go:33
------------------------------
+ [SLOW TEST] [11.384 seconds]
ExitMatcher with no exit code should say the right things when it fails
D:/main/dev/onsi/gomega/gexec/exit_matcher_test.go:53
------------------------------
+ [SLOW TEST] [11.386 seconds]
ExitMatcher with an exit code should say the right things when it fails
D:/main/dev/onsi/gomega/gexec/exit_matcher_test.go:75
------------------------------
+ [SLOW TEST] [15.014 seconds]
.CompileTestWithEnvironment a remote package compiles the specified test package with the specified env vars
D:/main/dev/onsi/gomega/gexec/build_test.go:205
------------------------------
+ [SLOW TEST] [12.938 seconds]
ExitMatcher bailing out early should bail out early once the process exits
D:/main/dev/onsi/gomega/gexec/exit_matcher_test.go:106
------------------------------
+ [SLOW TEST] [9.429 seconds]
.CompiledTestIn appends the gopath env var
D:/main/dev/onsi/gomega/gexec/build_test.go:263
------------------------------
+ [SLOW TEST] [9.614 seconds]
.CompiledTestIn resets GOPATH to its original value
D:/main/dev/onsi/gomega/gexec/build_test.go:269
------------------------------
+ [SLOW TEST] [17.306 seconds]
.Build when there have been previous calls to CompileTest compiles the specified package
D:/main/dev/onsi/gomega/gexec/build_test.go:23
------------------------------
+ [SLOW TEST] [17.556 seconds]
.Build when there have been previous calls to CompileTest and CleanupBuildArtifacts has been called compiles the specified package
D:/main/dev/onsi/gomega/gexec/build_test.go:35
------------------------------
+ [SLOW TEST] [14.740 seconds]
.CompileTest a remote package compiles the specified test package
D:/main/dev/onsi/gomega/gexec/build_test.go:137
------------------------------
+ [SLOW TEST] [18.354 seconds]
.Build when there have been previous calls to Build compiles the specified package
D:/main/dev/onsi/gomega/gexec/build_test.go:49
------------------------------
+ [SLOW TEST] [18.148 seconds]
.Build when there have been previous calls to Build and CleanupBuildArtifacts has been called compiles the specified package
D:/main/dev/onsi/gomega/gexec/build_test.go:60
------------------------------
+ [SLOW TEST] [16.027 seconds]
.CompileTest when there have been previous calls to CompileTest compiles the specified test package
D:/main/dev/onsi/gomega/gexec/build_test.go:150
------------------------------
+ [SLOW TEST] [13.085 seconds]
.CompileTest when there have been previous calls to CompileTest and CleanupBuildArtifacts has been called compiles the specified test package
D:/main/dev/onsi/gomega/gexec/build_test.go:161
------------------------------
+ [SLOW TEST] [10.293 seconds]
.CompileTest when there have been previous calls to Build compiles the specified test package
D:/main/dev/onsi/gomega/gexec/build_test.go:175
------------------------------
+ [SLOW TEST] [10.335 seconds]
.CompileTest when there have been previous calls to Build and CleanupBuildArtifacts has been called compiles the specified test package
D:/main/dev/onsi/gomega/gexec/build_test.go:186
------------------------------
+ [SLOW TEST] [69.807 seconds]
.CompiledTestIn a remote package compiles the specified test package
D:/main/dev/onsi/gomega/gexec/build_test.go:256
------------------------------
 SUCCESS! 1m19.3583568s
[1661410384] GHTTP Suite - 76/76 specs - 11 procs ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ SUCCESS! 119.3532ms
[1661410384] Gleak Suite - 34/34 specs - 11 procs ++++++++++++++++++++++++++++++
------------------------------
+ [FAILED] [1.011 seconds]
HaveLeaked failure messages [It] returns a negated failure message
D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:146

  Expected
      <string>: Expected not to leak 2 goroutines:
          goroutine 7 [syscall, locked to thread]
              syscall.SyscallN(0x58b465?, {0xc00006bd20?, 0xa232d4?, 0x8?}) at runtime/syscall_windows.go:557
              syscall.Syscall6(0xc000039260?, 0x8000?, 0x4?, 0xc00006bdd0?, 0x528753?, 0x51e767?, 0x58?, 0x46840?) at runtime/syscall_windows.go:501
              syscall.readFile(0x52808b?, {0xc000380000?, 0x8000, 0x800000?}, 0x7ffff800000?, 0x2?) at syscall/zsyscall_windows.go:1024
              syscall.ReadFile(...) at syscall/syscall_windows.go:400
              syscall.Read(0xc000346000?, {0xc000380000?, 0x99d2a0?, 0x0?}) at syscall/syscall_windows.go:379
              internal/poll.(*FD).Read(0xc000346000, {0xc000380000, 0x8000, 0x8000}) at poll/fd_windows.go:427
              os.(*File).read(...) at os/file_posix.go:31
              os.(*File).Read(0xc000332028, {0xc000380000?, 0xc000008870?, 0xaf4880?}) at os/file.go:118
              io.copyBuffer({0xaf4360, 0xc000008870}, {0xaf46a0, 0xc000332028}, {0x0, 0x0, 0x0}) at io/io.go:427
              io.Copy(...) at io/io.go:386
              github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1.1() at internal/output_interceptor.go:159
              created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1 at internal/output_interceptor.go:158
          goroutine 37 [chan receive]
              github.com/onsi/gomega/gleak.glob..func2.5.1.1() at gleak/have_leaked_matcher_test.go:128
              created by github.com/onsi/gomega/gleak.glob..func2.5.1 at gleak/have_leaked_matcher_test.go:127
  to match regular expression
      <string>: Expected not to leak 1 goroutines:
          goroutine \d+ \[.+\]
              .* at .*:\d+
              created by .* at .*:\d+
  In [It] at: D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:150
------------------------------
+ [FAILED] [1.014 seconds]
HaveLeaked failure messages [It] returns a failure message
D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:136

  Expected
      <string>: Expected to leak 2 goroutines:
          goroutine 5 [syscall, locked to thread]
              syscall.SyscallN(0x58b465?, {0xc00006dd20?, 0xa232d4?, 0x8?}) at runtime/syscall_windows.go:557
              syscall.Syscall6(0xc00008f230?, 0x8000?, 0x4?, 0xc00006ddd0?, 0x528753?, 0x51e767?, 0x58?, 0x46840?) at runtime/syscall_windows.go:501
              syscall.readFile(0x52808b?, {0xc000300000?, 0x8000, 0x800000?}, 0x7ffff800000?, 0x2?) at syscall/zsyscall_windows.go:1024
              syscall.ReadFile(...) at syscall/syscall_windows.go:400
              syscall.Read(0xc000224000?, {0xc000300000?, 0x99d2a0?, 0x0?}) at syscall/syscall_windows.go:379
              internal/poll.(*FD).Read(0xc000224000, {0xc000300000, 0x8000, 0x8000}) at poll/fd_windows.go:427
              os.(*File).read(...) at os/file_posix.go:31
              os.(*File).Read(0xc000204018, {0xc000300000?, 0xc000008030?, 0xaf4880?}) at os/file.go:118
              io.copyBuffer({0xaf4360, 0xc000008030}, {0xaf46a0, 0xc000204018}, {0x0, 0x0, 0x0}) at io/io.go:427
              io.Copy(...) at io/io.go:386
              github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1.1() at internal/output_interceptor.go:159
              created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1 at internal/output_interceptor.go:158
          goroutine 37 [chan receive]
              github.com/onsi/gomega/gleak.glob..func2.5.1.1() at gleak/have_leaked_matcher_test.go:128
              created by github.com/onsi/gomega/gleak.glob..func2.5.1 at gleak/have_leaked_matcher_test.go:127
  to match regular expression
      <string>: Expected to leak 1 goroutines:
          goroutine \d+ \[.+\]
              .* at .*:\d+
              created by .* at .*:\d+
  In [It] at: D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:140
------------------------------
+ [FAILED] [2.006 seconds]
HaveLeaked [It] considers testing and runtime goroutines not to be leaks
D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:77

  Timed out after 2.006s.
  should not find any leaks by default
  Expected not to leak 4 goroutines:
      goroutine 18 [IO wait]
          internal/poll.runtime_pollWait(0x146640f5ee8, 0x72) at runtime/netpoll.go:305
          internal/poll.(*pollDesc).wait(0xc00007fbb8?, 0x8e5c05?, 0x0) at poll/fd_poll_runtime.go:84
          internal/poll.execIO(0xc0001e8798, 0xa69838) at poll/fd_windows.go:175
          internal/poll.(*FD).Read(0xc0001e8780, {0xc00009d000, 0x1000, 0x1000}) at poll/fd_windows.go:441
          net.(*netFD).Read(0xc0001e8780, {0xc00009d000?, 0xc00001fb1e?, 0x16?}) at net/fd_posix.go:55
          net.(*conn).Read(0xc00000a5c0, {0xc00009d000?, 0xc00001fb1e?, 0x987ea0?}) at net/net.go:183
          bufio.(*Reader).Read(0xc000086120, {0xc000094010, 0x1, 0xc00007fd70?}) at bufio/bufio.go:237
          io.ReadAtLeast({0xaf3e80, 0xc000086120}, {0xc000094010, 0x1, 0x9}, 0x1) at io/io.go:332
          io.ReadFull(...) at io/io.go:351
          encoding/gob.decodeUintReader({0xaf3e80?, 0xc000086120?}, {0xc000094010?, 0x9?, 0x9?}) at gob/decode.go:120
          encoding/gob.(*Decoder).recvMessage(0xc000096080) at gob/decoder.go:81
          encoding/gob.(*Decoder).decodeTypeSequence(0xc000096080, 0x0) at gob/decoder.go:146
          encoding/gob.(*Decoder).DecodeValue(0xc000096080, {0x97f760?, 0xc0001ef260?, 0x1463e520108?}) at gob/decoder.go:225
          encoding/gob.(*Decoder).Decode(0xc000096080, {0x97f760?, 0xc0001ef260?}) at gob/decoder.go:202
          net/rpc.(*gobClientCodec).ReadResponseHeader(0x9a9a60?, 0x9796a0?) at rpc/client.go:228
          net/rpc.(*Client).input(0xc0000861e0) at rpc/client.go:109
          created by net/rpc.NewClientWithCodec at rpc/client.go:206
      goroutine 22 [select]
          github.com/onsi/ginkgo/v2/internal.startPipeFactory(0xc000076420, 0xc0000ac240) at internal/output_interceptor.go:77
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting at internal/output_interceptor.go:143
      goroutine 25 [select]
          github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1() at internal/output_interceptor.go:163
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting at internal/output_interceptor.go:153
      goroutine 27 [syscall, locked to thread]
          syscall.SyscallN(0x93ada5?, {0xc00021bd20?, 0x57d421?, 0x0?}) at runtime/syscall_windows.go:557
          syscall.Syscall6(0x0?, 0x0?, 0x0?, 0x0?, 0x0?, 0x0?, 0x0?, 0x0?) at runtime/syscall_windows.go:501
          syscall.readFile(0x0?, {0xc000380000?, 0x8000, 0x800000?}, 0x7ffff800000?, 0x2?) at syscall/zsyscall_windows.go:1024
          syscall.ReadFile(...) at syscall/syscall_windows.go:400
          syscall.Read(0xc0001e8f00?, {0xc000380000?, 0xc000380000?, 0x8000?}) at syscall/syscall_windows.go:379
          internal/poll.(*FD).Read(0xc0001e8f00, {0xc000380000, 0x8000, 0x8000}) at poll/fd_windows.go:427
          os.(*File).read(...) at os/file_posix.go:31
          os.(*File).Read(0xc00000a600, {0xc000380000?, 0xc0000931b8?, 0x1?}) at os/file.go:118
          io.copyBuffer({0xaf4360, 0xc0000931b8}, {0xaf46a0, 0xc00000a600}, {0x0, 0x0, 0x0}) at io/io.go:427
          io.Copy(...) at io/io.go:386
          github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1.1() at internal/output_interceptor.go:159
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1 at internal/output_interceptor.go:158
  In [It] at: D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:79
------------------------------
+ [FAILED] [2.006 seconds]
HaveLeaked when using signals [It] doesn't find leaks
D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:84

  Timed out after 2.006s.
  found signal.Notify leaks
  Expected not to leak 4 goroutines:
      goroutine 5 [syscall, locked to thread]
          syscall.SyscallN(0x1000?, {0xc00006bd20?, 0x8000?, 0x1b8072dffff?}) at runtime/syscall_windows.go:557
          syscall.Syscall6(0x1b806fab9c0?, 0x8000?, 0x4?, 0xc00006bdd0?, 0x528753?, 0xc00003c0c0?, 0x96dbfd?, 0xd79c00?) at runtime/syscall_windows.go:501
          syscall.readFile(0x52808b?, {0xc000380000?, 0x8000, 0x800000?}, 0x7ffff800000?, 0x2?) at syscall/zsyscall_windows.go:1024
          syscall.ReadFile(...) at syscall/syscall_windows.go:400
          syscall.Read(0xc00030c500?, {0xc000380000?, 0x2?, 0x0?}) at syscall/syscall_windows.go:379
          internal/poll.(*FD).Read(0xc00030c500, {0xc000380000, 0x8000, 0x8000}) at poll/fd_windows.go:427
          os.(*File).read(...) at os/file_posix.go:31
          os.(*File).Read(0xc0000c4b78, {0xc000380000?, 0xc000008048?, 0xaf4880?}) at os/file.go:118
          io.copyBuffer({0xaf4360, 0xc000008048}, {0xaf46a0, 0xc0000c4b78}, {0x0, 0x0, 0x0}) at io/io.go:427
          io.Copy(...) at io/io.go:386
          github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1.1() at internal/output_interceptor.go:159
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1 at internal/output_interceptor.go:158
      goroutine 20 [IO wait]
          internal/poll.runtime_pollWait(0x1b82cf15130, 0x72) at runtime/netpoll.go:305
          internal/poll.(*pollDesc).wait(0xc00048fbb8?, 0x8e5c05?, 0x0) at poll/fd_poll_runtime.go:84
          internal/poll.execIO(0xc000230298, 0xa69838) at poll/fd_windows.go:175
          internal/poll.(*FD).Read(0xc000230280, {0xc0001bf000, 0x1000, 0x1000}) at poll/fd_windows.go:441
          net.(*netFD).Read(0xc000230280, {0xc0001bf000?, 0xc0001fe120?, 0x16?}) at net/fd_posix.go:55
          net.(*conn).Read(0xc000208018, {0xc0001bf000?, 0xc0001fe120?, 0x987ea0?}) at net/net.go:183
          bufio.(*Reader).Read(0xc0000d8360, {0xc00009f590, 0x1, 0xc00048fd70?}) at bufio/bufio.go:237
          io.ReadAtLeast({0xaf3e80, 0xc0000d8360}, {0xc00009f590, 0x1, 0x9}, 0x1) at io/io.go:332
          io.ReadFull(...) at io/io.go:351
          encoding/gob.decodeUintReader({0xaf3e80?, 0xc0000d8360?}, {0xc00009f590?, 0x9?, 0x9?}) at gob/decode.go:120
          encoding/gob.(*Decoder).recvMessage(0xc0000ce380) at gob/decoder.go:81
          encoding/gob.(*Decoder).decodeTypeSequence(0xc0000ce380, 0x0) at gob/decoder.go:146
          encoding/gob.(*Decoder).DecodeValue(0xc0000ce380, {0x97f760?, 0xc000200600?, 0x1b806fa0a28?}) at gob/decoder.go:225
          encoding/gob.(*Decoder).Decode(0xc0000ce380, {0x97f760?, 0xc000200600?}) at gob/decoder.go:202
          net/rpc.(*gobClientCodec).ReadResponseHeader(0x9a9a60?, 0x9796a0?) at rpc/client.go:228
          net/rpc.(*Client).input(0xc0000d8420) at rpc/client.go:109
          created by net/rpc.NewClientWithCodec at rpc/client.go:206
      goroutine 24 [select]
          github.com/onsi/ginkgo/v2/internal.startPipeFactory(0xc00023a1e0, 0xc000086480) at internal/output_interceptor.go:77
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting at internal/output_interceptor.go:143
      goroutine 29 [select]
          github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1() at internal/output_interceptor.go:163
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting at internal/output_interceptor.go:153
  In [It] at: D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:88
------------------------------


Summarizing 4 Failures:
  [FAIL] HaveLeaked failure messages [It] returns a negated failure message
  D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:150
  [FAIL] HaveLeaked failure messages [It] returns a failure message
  D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:140
  [FAIL] HaveLeaked [It] considers testing and runtime goroutines not to be leaks
  D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:79
  [FAIL] HaveLeaked when using signals [It] doesn't find leaks
  D:/main/dev/onsi/gomega/gleak/have_leaked_matcher_test.go:88

Ran 34 of 34 Specs in 2.014 seconds
FAIL! -- 30 Passed | 4 Failed | 0 Pending | 0 Skipped


Ginkgo ran 12 suites in 1m41.312693s

There were failures detected in the following suites:
  gleak .\gleak

Test Suite Failed

[thediveo]

Hi @davidhsingyuchen, thank you for reporting this issue!

I've been able to reproduce it and most can be automatically handled with an updated ignore list.

@onsi I need to pick your brain on ginkgo -p here, as I have an rpc.Client-related goroutine that seems to be related to when running the target under test via ginkgo -p. If I run the tests via ginkgo without -p I don't see this goroutine, so I suspect it is related to some communication between ginkgo and gomega?

$ ginkgo -p ./gleak/
Running Suite: Gleak Suite - C:\github\gomega\gleak
===================================================
Random Seed: 1661416707

Will run 1 of 34 specs
Running in parallel across 11 processes
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
+ [FAILED] [2.015 seconds]
HaveLeaked
C:/github/gomega/gleak/have_leaked_matcher_test.go:16
  [It] considers testing and runtime goroutines not to be leaks
  C:/github/gomega/gleak/have_leaked_matcher_test.go:77

  Timed out after 2.014s.
  should not find any leaks by default
  Expected not to leak 1 goroutines:
      goroutine 9 [IO wait]
          internal/poll.runtime_pollWait(0x137592c5eb8, 0x72) at runtime/netpoll.go:305
          internal/poll.(*pollDesc).wait(0xc00007dbb8?, 0xc85c05?, 0x0) at poll/fd_poll_runtime.go:84
          internal/poll.execIO(0xc0001e6798, 0xe0a8d8) at poll/fd_windows.go:175
          internal/poll.(*FD).Read(0xc0001e6780, {0xc000314000, 0x1000, 0x1000}) at poll/fd_windows.go:441
          net.(*netFD).Read(0xc0001e6780, {0xc000314000?, 0xc00034bbfd?, 0x16?}) at net/fd_posix.go:55
          net.(*conn).Read(0xc00000a598, {0xc000314000?, 0xc00034bbfd?, 0xd28ea0?}) at net/net.go:183
          bufio.(*Reader).Read(0xc00003c3c0, {0xc00001da00, 0x1, 0xc00007dd70?}) at bufio/bufio.go:237
          io.ReadAtLeast({0xe94f80, 0xc00003c3c0}, {0xc00001da00, 0x1, 0x9}, 0x1) at io/io.go:332
          io.ReadFull(...) at io/io.go:351
          encoding/gob.decodeUintReader({0xe94f80?, 0xc00003c3c0?}, {0xc00001da00?, 0x9?, 0x9?}) at gob/decode.go:120
          encoding/gob.(*Decoder).recvMessage(0xc00011a480) at gob/decoder.go:81
          encoding/gob.(*Decoder).decodeTypeSequence(0xc00011a480, 0x0) at gob/decoder.go:146
          encoding/gob.(*Decoder).DecodeValue(0xc00011a480, {0xd20760?, 0xc0002820c0?, 0x137336c0eb8?}) at gob/decoder.go:225
          encoding/gob.(*Decoder).Decode(0xc00011a480, {0xd20760?, 0xc0002820c0?}) at gob/decoder.go:202
          net/rpc.(*gobClientCodec).ReadResponseHeader(0xd4aa60?, 0xd1a6a0?) at rpc/client.go:228
          net/rpc.(*Client).input(0xc00003c480) at rpc/client.go:109
          created by net/rpc.NewClientWithCodec at rpc/client.go:206
  In [It] at: C:/github/gomega/gleak/have_leaked_matcher_test.go:79
------------------------------

Ran 1 of 34 Specs in 2.248 seconds
FAIL! -- 0 Passed | 1 Failed | 0 Pending | 33 Skipped

If it is, can you give me a hint how I might be able to deal with it? I don't think that adding net/rpc.NewClientWithCodec to the ignore list is a good thing to do, as this would make lots of RPC-related tests blind to client go routine leakages.

[thediveo]

The solution I've now come up with is to call a new IgnoreGinkgoParallelClient() in BeforeSuite in order to update the suite's gleak ignore list with the dynamically found go routines that hopefully relate to Ginkgo's parallel client.

[onsi]

hey @thediveo - my bad here, I had assumed that Gomega's CI was running the tests in parallel and would have caught this issue sooner. When I ran locally I didn't think to try running in parallel which, in retrospect, was an obvious gap on my part.

I'm able to reproduce this on my MacOS box by simply running ginkgo -p.

When running in parallel ginkgo spawns multiple processes that then communicate back to the CLI using an RPC client. On Unix/Darwin (but not on windows as it is not supported), Ginkgo also runs goroutines on each parallel process that intercept the stdout/stderr of that process in order to associate it with the spec and pass it back to the server.

On windows you see the rpc.NewClientWithCodec leak above. On Unix/Darwin I see both rpc.NewClientWithCodec and leaks that look like:

------------------------------
• [FAILED] [2.001 seconds]
HaveLeaked
/Users/onsi/code/gomega/gleak/have_leaked_matcher_test.go:16
  [It] considers testing and runtime goroutines not to be leaks
  /Users/onsi/code/gomega/gleak/have_leaked_matcher_test.go:77

  Timed out after 2.001s.
  should not find any leaks by default
  Expected not to leak 4 goroutines:
      goroutine 19 [IO wait]
          internal/poll.runtime_pollWait(0x128c510a0, 0x72) at runtime/netpoll.go:305
          internal/poll.(*pollDesc).wait(0x1400015c080?, 0x14000162000?, 0x0) at poll/fd_poll_runtime.go:84
          internal/poll.(*pollDesc).waitRead(...) at poll/fd_poll_runtime.go:89
          internal/poll.(*FD).Read(0x1400015c080, {0x14000162000, 0x1000, 0x1000}) at poll/fd_unix.go:167
          net.(*netFD).Read(0x1400015c080, {0x14000162000?, 0x1400017bc58?, 0x100da418c?}) at net/fd_posix.go:55
          net.(*conn).Read(0x1400011c018, {0x14000162000?, 0x1400017bc58?, 0x100da40b4?}) at net/net.go:183
          bufio.(*Reader).Read(0x1400010e0c0, {0x14000116400, 0x1, 0x100da419c?}) at bufio/bufio.go:237
          io.ReadAtLeast({0x100fa5da0, 0x1400010e0c0}, {0x14000116400, 0x1, 0x9}, 0x1) at io/io.go:332
          io.ReadFull(...) at io/io.go:351
          encoding/gob.decodeUintReader({0x100fa5da0?, 0x1400010e0c0?}, {0x14000116400?, 0x9?, 0x9?}) at gob/decode.go:120
          encoding/gob.(*Decoder).recvMessage(0x1400015c100) at gob/decoder.go:81
          encoding/gob.(*Decoder).decodeTypeSequence(0x1400015c100, 0x0) at gob/decoder.go:146
          encoding/gob.(*Decoder).DecodeValue(0x1400015c100, {0x100f04020?, 0x140002022a0?, 0x1400051a478?}) at gob/decoder.go:225
          encoding/gob.(*Decoder).Decode(0x1400015c100, {0x100f04020?, 0x140002022a0?}) at gob/decoder.go:202
          net/rpc.(*gobClientCodec).ReadResponseHeader(0x100f2e440?, 0x100efe1a0?) at rpc/client.go:228
          net/rpc.(*Client).input(0x1400010e180) at rpc/client.go:109
          created by net/rpc.NewClientWithCodec at rpc/client.go:206
      goroutine 21 [select]
          github.com/onsi/ginkgo/v2/internal.startPipeFactory(0x1400014c1e0, 0x1400014c4e0) at internal/output_interceptor.go:77
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting at internal/output_interceptor.go:143
      goroutine 25 [select]
          github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1() at internal/output_interceptor.go:163
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting at internal/output_interceptor.go:153
      goroutine 11 [IO wait]
          internal/poll.runtime_pollWait(0x128c50ce0, 0x72) at runtime/netpoll.go:305
          internal/poll.(*pollDesc).wait(0x140000828a0?, 0x140002a6000?, 0x1) at poll/fd_poll_runtime.go:84
          internal/poll.(*pollDesc).waitRead(...) at poll/fd_poll_runtime.go:89
          internal/poll.(*FD).Read(0x140000828a0, {0x140002a6000, 0x8000, 0x8000}) at poll/fd_unix.go:167
          os.(*File).read(...) at os/file_posix.go:31
          os.(*File).Read(0x140000105a8, {0x140002a6000?, 0x1400000e9a8?, 0x100a46b9c?}) at os/file.go:118
          io.copyBuffer({0x100fa6260, 0x1400000e9a8}, {0x100fa65a0, 0x140000105a8}, {0x0, 0x0, 0x0}) at io/io.go:427
          io.Copy(...) at io/io.go:386
          github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1.1() at internal/output_interceptor.go:159
          created by github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor).ResumeIntercepting.func1 at internal/output_interceptor.go:158
  In [It] at: /Users/onsi/code/gomega/gleak/have_leaked_matcher_test.go:79
------------------------------

this is the stdout/stderr intercepting stuff I was talking about earlier. I can fix this leak by adding:

	IgnoringCreator("github.com/onsi/ginkgo/v2/internal.(*genericOutputInterceptor)..."),

to the standardFilters in have_leaked_matcher.go.

The rpc client is tricky. It goes away if I take a snapshot in a BeforeSuite and use that in the failing tests. Similar to IgnoreGinkgoParallelClient() in BeforeSuite() that you describe. I don't know that there's a better way to handle this. At the top of BeforeSuite is a safe place to do this and we could rename it to something like RecordBaselineGoroutines() or something and present it as a best-practice.

Can you think of anything I could do on the Ginkgo side? I don't think so, since the goroutine is created in the go library code by calling a private function and the goroutine stack ends at the creator and not the creator's caller (where all the ginkgo references would live).

[thediveo]

After finally locating the internal parallel stuff in Ginkgo and looking at it I don't see a good way to integrate here, so I would propose to stay with an upgraded ignore list and the BeforeSuite way. I've all the things ready for a PR, just adding a small paragraph to the doc that when not liking the BeforeSuite way, then using the snapshot solution instead.

[onsi]

Thanks @thediveo - sorry for not catching this sooner, but I agree that that sounds like the best solution.

[thediveo]

I didn't noticed either, as I have to admit that I routinely use go test -p=1 ... ./... not least as a lot of my code needs added capabilities/privileges and is thus easily tested as root and not in parallel when spinning up test containers.

I would rather keep the specialized IgnoreGinkgoParallelClient as it is geared towards Ginkgo infrastructure. I'll see that the documentation updates cover the variants; we already have the BeforeEach(...DeferredAfter()) approach as an alternative.

Somehow slightly ironic that we follows Go's principle of not hiding to many things but instead making clear what happens.