Skip to content

feat(go_port_test): reproduce test of race condition of shutdown with non-empty queue - #880

Open
Schrodinger257 wants to merge 2 commits into
metacall:developfrom
Schrodinger257:go_port_goroutines_leak_test
Open

Schrodinger257 wants to merge 2 commits into
metacall:developfrom
Schrodinger257:go_port_goroutines_leak_test

Conversation

@Schrodinger257

@Schrodinger257 Schrodinger257 commented Sep 12, 2026

Copy link
Copy Markdown

Description

This test calls Call() function in a goroutine to fill the queue and calls Destroy() in a goroutine after 2ms for both of them to work concurrently to reproduce the race condition of shutdown with non-empty queue. the problem is as follows when calling Destroy() with non-empty queue toggle chan is closed and so C.metacall_destroy execute and a deadlock occur and block on either Call() waits for <-ret to return a value or Destroy() block on wg.Wait() waiting for workers to finish. the test uses runtime/pprof to generate a goroutine profile to detect leaked goroutines after test finishes. you can see and verify the profile file using "go tools pprof Goroutine_leaks_report.pprof" command.

result of running go test -v -race -timeout 10s -run TestGoRoutineLeaks shows a data race caught with go thread sanitizer

WARNING: DATA RACE
Write at 0x000001754228 by goroutine 110:
  runtime.racewrite()
      <autogenerated>:1 +0x1e
  github.com/metacall/core/source/ports/go_port/source.TestGoRoutineLeaks.func2()
      /mnt/Work/Projects/MetaCall/core/source/ports/go_port/source/go_port_test.go:241 +0x37

Previous read at 0x000001754228 by goroutine 11:
  runtime.raceread()
      <autogenerated>:1 +0x1e
  github.com/metacall/core/source/ports/go_port/source.TestGoRoutineLeaks.func1()
      /mnt/Work/Projects/MetaCall/core/source/ports/go_port/source/go_port_test.go:232 +0xb6

Goroutine 110 (running) created at:
  github.com/metacall/core/source/ports/go_port/source.TestGoRoutineLeaks()
      /mnt/Work/Projects/MetaCall/core/source/ports/go_port/source/go_port_test.go:240 +0x352
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:2036 +0x21c
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:2101 +0x38

Goroutine 11 (running) created at:
  github.com/metacall/core/source/ports/go_port/source.TestGoRoutineLeaks()
      /mnt/Work/Projects/MetaCall/core/source/ports/go_port/source/go_port_test.go:225 +0x147
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:2036 +0x21c
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:2101 +0x38
==================
    go_port_test.go:267: Shutdown deadlock: goroutine leaks detected
    testing.go:1712: race detected during execution of test
--- FAIL: TestGoRoutineLeaks (5.01s)
FAIL
exit status 1
FAIL    github.com/metacall/core/source/ports/go_port/source    5.072s

goroutine profile output shows 100 goroutine leaks:

ROUTINE ======================== github.com/metacall/core/source/ports/go_port/source.TestGoRoutineLeaks.func1 in /mnt/Work/Projects/MetaCall/core/source/ports/go_port/source/go_port_test.go
         0        100 (flat, cum) 97.09% of Total
         .          .    225:           go func() {
         .          .    226:                   defer wg.Done()
         .          .    227:                   for {
         .          .    228:                           select {
         .          .    229:                           case <-stop:
         .          .    230:                                   return
         .          .    231:                           default:
         .        100    232:                                   Call("leak_test", "warmup")
         .          .    233:                           }
         .          .    234:                   }
         .          .    235:           }()
         .          .    236:   }
         .          .    237:
ROUTINE ======================== github.com/metacall/core/source/ports/go_port/source.TestGoRoutineLeaks.func2 in /mnt/Work/Projects/MetaCall/core/source/ports/go_port/source/go_port_test.go
         0          1 (flat, cum)  0.97% of Total
         .          .    240:   go func() {
         .          1    241:           Destroy()
         .          .    242:           close(stop)
         .          .    243:           wg.Wait()
         .          .    244:           close(shutdown)
         .          .    245:   }()
         .          .    246:

The test was executed with the fix in PR #875 and the deadlock was removed and goroutine profile showed no leaks.

output of go test -v -race -timeout 10s -run TestGoRoutineLeaks

=== RUN   TestGoRoutineLeaks
--- PASS: TestGoRoutineLeaks (0.01s)
PASS
ok      github.com/metacall/core/source/ports/go_port/source    1.113s

goroutine profile output:

         0          1 (flat, cum) 50.00% of Total
         .          .    219:   const ws = 100
         .          .    220:   stop := make(chan interface{})
         .          .    221:   shutdown := make(chan interface{})
         .          .    222:   var wg sync.WaitGroup
         .          .    223:   // start concurrent callers
         .          .    224:   for i := 0; i < ws; i++ {
         .          .    225:           wg.Add(1)
         .          .    226:           go func() {
         .          .    227:                   defer wg.Done()
         .          .    228:                   for {
         .          .    229:                           select {
         .          .    230:                           case <-stop:
         .          .    231:                                   return
         .          .    232:                           default:
         .          .    233:                                   Call("leak_test", "warmup")
         .          .    234:                           }
         .          .    235:                   }
         .          .    236:           }()
         .          .    237:   }
         .          .    238:
         .          .    239:   // call Destroy() to start shutdown concurrently with worker register in queue
         .          .    240:   time.Sleep(2 * time.Millisecond)
         .          .    241:   go func() {
         .          .    242:           Destroy()
         .          .    243:           close(stop)
         .          .    244:           wg.Wait()
         .          .    245:           close(shutdown)
         .          .    246:   }()

… non-empty queue

this test reproduce the following problem. when calling Destroy() with non-empty queue a deadlock occur and block on either Call() waits for <-ret to return a value or Destroy() block on wg.Wait(). you can see and verify the profile file using "go tools pprof filename.pprof" command
@viferga

viferga commented Sep 14, 2026

Copy link
Copy Markdown
Member

I need the instrumentation you have used included into the tests so we can verify in the CI that it fails, if you need help of how to define tests in cmake I can help you on that.

@Schrodinger257

Copy link
Copy Markdown
Author

I need the instrumentation you have used included into the tests so we can verify in the CI that it fails, if you need help of how to define tests in cmake I can help you on that.

I used go theead sanitizer using -race flag in go test . -race which showed a data race warning and used a tool in go called pprof that creates a profiles that monitor a specific item like heap memory or goroutines. The profile i used is goroutine profile. I imported the library then captured the goroutine profile using pprof.Lookup("goroutine") then stored it in a .pprof file then displayed it using command go tool pprof file_name.pprof and found the 100 leaked goroutines. I tried to use cmake tests using c thread sanitizer but i got a segfault as c and go both uses the same sanitizer runtime which created a conflict.

@viferga

viferga commented Sep 15, 2026

Copy link
Copy Markdown
Member

Everything you used must be added to the project so it's tested during CI. What are all the commands did you use?

@Schrodinger257

Copy link
Copy Markdown
Author

Everything you used must be added to the project so it's tested during CI. What are all the commands did you use?

go test . -race
go tool pprof Goroutine_leaks_report.pprof

@viferga

viferga commented Sep 15, 2026

Copy link
Copy Markdown
Member

Everything you used must be added to the project so it's tested during CI. What are all the commands did you use?

go test . -race go tool pprof Goroutine_leaks_report.pprof

What does the second command?
We must convert this into a cmake target/test, do you want me to explain you how?

@Schrodinger257

Copy link
Copy Markdown
Author

Everything you used must be added to the project so it's tested during CI. What are all the commands did you use?

go test . -race go tool pprof Goroutine_leaks_report.pprof

What does the second command? We must convert this into a cmake target/test, do you want me to explain you how?

the second command is not important it only shows the number of leaked goroutines and do not trigger any warnings or failures signs. do you still want to use the second command in cmake ?

@viferga

viferga commented Sep 15, 2026

Copy link
Copy Markdown
Member

Everything you used must be added to the project so it's tested during CI. What are all the commands did you use?

go test . -race go tool pprof Goroutine_leaks_report.pprof

What does the second command? We must convert this into a cmake target/test, do you want me to explain you how?

the second command is not important it only shows the number of leaked goroutines and do not trigger any warnings or failures signs. do you still want to use the second command in cmake ?

Yes I will show it, this can give us more information in the CI when debugging, the test must fail if the go test fails or there is data races or leaks.

If you need you can define how a test passes by filtering the text in the output of the command. I mean if it doesn't do exit 1 or similar when it fails...

@Schrodinger257

Copy link
Copy Markdown
Author

Everything you used must be added to the project so it's tested during CI. What are all the commands did you use?

go test . -race go tool pprof Goroutine_leaks_report.pprof

What does the second command? We must convert this into a cmake target/test, do you want me to explain you how?

the second command is not important it only shows the number of leaked goroutines and do not trigger any warnings or failures signs. do you still want to use the second command in cmake ?

Yes I will show it, this can give us more information in the CI when debugging, the test must fail if the go test fails or there is data races or leaks.

If you need you can define how a test passes by filtering the text in the output of the command. I mean if it doesn't do exit 1 or similar when it fails...

okay i will try to implement cmake test

@Schrodinger257

Copy link
Copy Markdown
Author

fixed go cmake tests and added support of thread sanitizer and goroutine profile to track leaked goroutines with limit of 20 goroutines, more than 20 exit with 1. ctest output showed failure of go_port test with a data race warning and with and failure of GO_pprof with 103 goroutines. command used: ctest -V -R "go_port | GO_pprof"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants