search

newscred / webhook-broker

This is a fully HTTP based Pub/Sub Broker with a goal to simplify system architecture in SOA or Microservice architecture. It aims to solve the inter service communication problem.
Apache License 2.0
18 stars 25 forks source link

[BUG] CLI Config Test fails intermittently during docker container build #52

Closed imyousuf closed 3 years ago

imyousuf commented 3 years ago

Describe the bug There is a intermittent issue about the following test failing in container build. Tried to add wait on write (5f6905dacb35492dae466d7f563c12b8314c1fb2) but that seemingly did not help.

panic: sync: negative WaitGroup counter

goroutine 24 [running]:
sync.(*WaitGroup).Add(0xc00009ea40, 0xffffffffffffffff)
    /usr/local/go/src/sync/waitgroup.go:74 +0x147
sync.(*WaitGroup).Done(...)
    /usr/local/go/src/sync/waitgroup.go:99
github.com/imyousuf/webhook-broker/config.TestCLIConfigPathChangeNotification.func1.1()
    /go/src/github.com/imyousuf/webhook-broker/config/cliconfig_test.go:45 +0x33
created by github.com/imyousuf/webhook-broker/config.glob..func2
    /go/src/github.com/imyousuf/webhook-broker/config/cliconfig.go:138 +0x9c
FAIL    github.com/imyousuf/webhook-broker/config   0.025s
?       github.com/imyousuf/webhook-broker/config/mocks [no test files]
ok      github.com/imyousuf/webhook-broker/controllers  1.140s
ok      github.com/imyousuf/webhook-broker/dispatcher   1.598s
?       github.com/imyousuf/webhook-broker/dispatcher/mocks [no test files]
ok      github.com/imyousuf/webhook-broker/storage  0.683s
ok      github.com/imyousuf/webhook-broker/storage/data 0.007s
?       github.com/imyousuf/webhook-broker/storage/mocks    [no test files]

To Reproduce Steps to reproduce the behavior:

  1. Some PR test or snyk build will fail

Expected behavior No intermittent test failure

imyousuf commented 3 years ago 
#27 [build-env 22/22] RUN make test
#27 0.077 go test -timeout 30s -mod=readonly ./...
#27 10.01 ok    github.com/***/webhook-broker   3.255s
#27 37.53 {"level":"error","time":"2021-01-12T18:07:55Z","message":"Encountered Wait error on file change notification"}
#27 37.53 panic: test timed out after 30s
#27 37.53 
#27 37.53 goroutine 5 [running]:
#27 37.53 testing.(*M).startAlarm.func1()
#27 37.53   /usr/local/go/src/testing/testing.go:1618 +0xe5
#27 37.53 created by time.goFunc
#27 37.53   /usr/local/go/src/time/sleep.go:167 +0x45
#27 37.53 
#27 37.53 goroutine 1 [chan receive]:
#27 37.53 testing.(*T).Run(0xc000086600, 0x90e1dd, 0x23, 0x91f548, 0x496506)
#27 37.53   /usr/local/go/src/testing/testing.go:1169 +0x2da
#27 37.53 testing.runTests.func1(0xc000086480)
#27 37.53   /usr/local/go/src/testing/testing.go:1439 +0x78
#27 37.53 testing.tRunner(0xc000086480, 0xc0000d1de0)
#27 37.53   /usr/local/go/src/testing/testing.go:1123 +0xef
#27 37.53 testing.runTests(0xc0000ae560, 0xb83860, 0xc, 0xc, 0xbff7974662694c89, 0x6fc2e586e, 0xbc4d40, 0x415130)
#27 37.53   /usr/local/go/src/testing/testing.go:1437 +0x2fe
#27 37.53 testing.(*M).Run(0xc000104080, 0x0)
#27 37.53   /usr/local/go/src/testing/testing.go:1345 +0x1eb
#27 37.53 main.main()
#27 37.53   _testmain.go:65 +0x138
#27 37.53 
#27 37.53 goroutine 19 [chan receive]:
#27 37.53 testing.(*T).Run(0xc000086900, 0x906bcf, 0x14, 0x91f4e0, 0x258e096da5)
#27 37.53   /usr/local/go/src/testing/testing.go:1169 +0x2da
#27 37.53 github.com/***/webhook-broker/config.TestCLIConfigPathChangeNotification(0xc000086600)
#27 37.53   /go/src/github.com/***/webhook-broker/config/cliconfig_test.go:49 +0x50
#27 37.53 testing.tRunner(0xc000086600, 0x91f548)
#27 37.53   /usr/local/go/src/testing/testing.go:1123 +0xef
#27 37.53 created by testing.(*T).Run
#27 37.53   /usr/local/go/src/testing/testing.go:1168 +0x2b3
#27 37.53 
#27 37.53 goroutine 20 [semacquire]:
#27 37.53 sync.runtime_Semacquire(0xc00009ea68)
#27 37.53   /usr/local/go/src/runtime/sema.go:56 +0x45
#27 37.53 sync.(*WaitGroup).Wait(0xc00009ea60)
#27 37.53   /usr/local/go/src/sync/waitgroup.go:130 +0x65
#27 37.53 github.com/***/webhook-broker/config.TestCLIConfigPathChangeNotification.func1(0xc000086900)
#27 37.53   /go/src/github.com/***/webhook-broker/config/cliconfig_test.go:77 +0x245
#27 37.53 testing.tRunner(0xc000086900, 0x91f4e0)
#27 37.53   /usr/local/go/src/testing/testing.go:1123 +0xef
#27 37.53 created by testing.(*T).Run
#27 37.53   /usr/local/go/src/testing/testing.go:1168 +0x2b3
#27 37.53 
#27 37.53 goroutine 21 [syscall]:
#27 37.53 syscall.Syscall6(0xe8, 0x8, 0xc00018fb6c, 0x7, 0xffffffffffffffff, 0x0, 0x0, 0x2, 0x17, 0x0)
#27 37.53   /usr/local/go/src/syscall/asm_linux_amd64.s:41 +0x5
#27 37.53 golang.org/x/sys/unix.EpollWait(0x8, 0xc00018fb6c, 0x7, 0x7, 0xffffffffffffffff, 0xc00018fc44, 0xc000066d00, 0x0)
#27 37.53   /go/pkg/mod/golang.org/x/sys@v0.0.0-20201029080932-201ba4db2418/unix/zsyscall_linux_amd64.go:76 +0x72
#27 37.53 github.com/fsnotify/fsnotify.(*fdPoller).wait(0xc0000d6600, 0xc00018fc00, 0x2, 0x0)
#27 37.53   /go/pkg/mod/github.com/fsnotify/fsnotify@v1.4.9/inotify_poller.go:86 +0x91
#27 37.53 github.com/fsnotify/fsnotify.(*Watcher).readEvents(0xc000080550)
#27 37.53   /go/pkg/mod/github.com/fsnotify/fsnotify@v1.4.9/inotify.go:192 +0x206
#27 37.53 created by github.com/fsnotify/fsnotify.NewWatcher
#27 37.53   /go/pkg/mod/github.com/fsnotify/fsnotify@v1.4.9/inotify.go:59 +0x1a8
#27 37.53 
#27 37.53 goroutine 22 [select]:
#27 37.53 github.com/***/webhook-broker/config.watchWorker(0xc000080550, 0xc0000a27e0)
#27 37.53   /go/src/github.com/***/webhook-broker/config/cliconfig.go:97 +0xd5
#27 37.53 created by github.com/***/webhook-broker/config.(*CLIConfig).watchFileIfExists
#27 37.53   /go/src/github.com/***/webhook-broker/config/cliconfig.go:91 +0x398

Despite having a random string in file and panic recovery test timed out!

imyousuf commented 3 years ago 
{"level":"debug","Content":"[broker]\n\tmax-message-queue-size=10000000\n\t","time":"2021-01-12T21:37:11Z","message":"Content generating hash for"}
{"level":"debug","writeOrCreateMask":2,"eventName":"../testdatadir/webhook-broker.change-test_2311588148755813194.cfg","time":"2021-01-12T21:37:11Z","message":"File change event"}
{"level":"debug","Content":"","time":"2021-01-12T21:37:11Z","message":"Content generating hash for"}
{"level":"debug","oldHash":"8ee96fea5605a342fdc8ed7bf1f144f9ffe63127be039e45aaf1968513afc1c1","newHash":"e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855","time":"2021-01-12T21:37:11Z","message":"Old and new hash"}
{"level":"debug","writeOrCreateMask":2,"eventName":"../testdatadir/webhook-broker.change-test_2311588148755813194.cfg","time":"2021-01-12T21:37:11Z","message":"File change event"}
{"level":"debug","Content":"[broker]\n\tmax-message-queue-size=1\n\t","time":"2021-01-12T21:37:11Z","message":"Content generating hash for"}
{"level":"debug","oldHash":"e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855","newHash":"f86bef2bb02bdddabaf408c171ce00bcb5662b5165d10831fb1e8e6e01c84b6d","time":"2021-01-12T21:37:11Z","message":"Old and new hash"}

Seemingly what is happening intermittently in test environment is, file is in truncated state long enough for notifier to notify; which is a content change and hence being correctly picked by our notifier.

It is safe to assume for our application that, if there is a configuration file to watch, then unless its deleted, we should ignore blank content and consider it a error.