kudobuilder / kudo

Kubernetes Universal Declarative Operator (KUDO)
https://kudo.dev
Apache License 2.0
1.18k stars 101 forks source link

e2e test hang #1283

Closed porridge closed 4 years ago

porridge commented 4 years ago

What happened:

I ran ./hack/run-e2e-tests.sh

[...]
Successfully tagged kudobuilder/controller:test
+ ./bin/kubectl-kudo init --dry-run --output yaml --kudo-image kudobuilder/controller:test
+ sed -E -e '/imagePullPolicy/ s/Always/Never/'
+ sed s/%version%/test/ kudo-e2e-test.yaml.tmpl
+ '[' false == true ']'
+ echo 'Running E2E tests without junit output'
+ ./bin/kubectl-kudo test --config kudo-e2e-test.yaml
Running E2E tests without junit output
=== RUN   kudo

It hang at this point for over 20 minutes. First time this happened to me.

What you expected to happen:

No hang.

How to reproduce it (as minimally and precisely as possible):

:man_shrugging:

Anything else we need to know?:

After hitting CTRL+\ I got the following:

./full-test.sh: linia 6: 27522 Wyjście                grc -c conf.gotest make imports lint integration-test e2e-test

real    27m24,720s
user    0m0,021s
sys 0m0,006s
SIGQUIT: quit
PC=0x463343 m=0 sigcode=128

goroutine 18 [syscall, 2 minutes]:
runtime.notetsleepg(0x2a43dc0, 0x12a0383e3, 0x0)
    /usr/local/go/src/runtime/lock_futex.go:227 +0x34 fp=0xc00006c760 sp=0xc00006c730 pc=0x40cda4
runtime.timerproc(0x2a43da0)
    /usr/local/go/src/runtime/time.go:311 +0x2f1 fp=0xc00006c7d8 sp=0xc00006c760 pc=0x450241
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc00006c7e0 sp=0xc00006c7d8 pc=0x461411
created by runtime.(*timersBucket).addtimerLocked
    /usr/local/go/src/runtime/time.go:169 +0x10e

goroutine 1 [chan receive, 25 minutes]:
testing.(*T).Run(0xc000395f00, 0x1a01ad6, 0x4, 0xc0002d5870, 0x48d0a6)
    /usr/local/go/src/testing/testing.go:961 +0x377
testing.runTests.func1(0xc000395e00)
    /usr/local/go/src/testing/testing.go:1202 +0x78
testing.tRunner(0xc000395e00, 0xc000631b98)
    /usr/local/go/src/testing/testing.go:909 +0xc9
testing.runTests(0xc0004b9660, 0xc0004b9640, 0x1, 0x1, 0x0)
    /usr/local/go/src/testing/testing.go:1200 +0x2a7
testing.(*M).Run(0xc000379600, 0x0)
    /usr/local/go/src/testing/testing.go:1117 +0x176
github.com/kudobuilder/kudo/pkg/test/utils.RunTests(0x1a01ad6, 0x4, 0x0, 0x0, 0x0, 0xc0002d5870)
    /home/porridge/Desktop/work/mesosphere/code/kudo/pkg/test/utils/testing.go:47 +0x211
github.com/kudobuilder/kudo/pkg/kudoctl/cmd.newTestCmd.func2(0xc00068e780, 0xc0004b8f00, 0x0, 0x2)
    /home/porridge/Desktop/work/mesosphere/code/kudo/pkg/kudoctl/cmd/test.go:163 +0xa4
github.com/spf13/cobra.(*Command).execute(0xc00068e780, 0xc0004b8ec0, 0x2, 0x2, 0xc00068e780, 0xc0004b8ec0)
    /home/porridge/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:830 +0x2aa
github.com/spf13/cobra.(*Command).ExecuteC(0xc000675900, 0x0, 0x74e00, 0xc000042118)
    /home/porridge/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914 +0x2fb
github.com/spf13/cobra.(*Command).Execute(...)
    /home/porridge/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
main.main()
    /home/porridge/Desktop/work/mesosphere/code/kudo/cmd/kubectl-kudo/main.go:24 +0x27

goroutine 6 [chan receive, 2 minutes]:
k8s.io/klog.(*loggingT).flushDaemon(0x2a3ee60)
    /home/porridge/go/pkg/mod/k8s.io/klog@v1.0.0/klog.go:1010 +0x8b
created by k8s.io/klog.init.0
    /home/porridge/go/pkg/mod/k8s.io/klog@v1.0.0/klog.go:411 +0xd6

goroutine 12 [syscall, 25 minutes]:
os/signal.signal_recv(0x0)
    /usr/local/go/src/runtime/sigqueue.go:147 +0x9c
os/signal.loop()
    /usr/local/go/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
    /usr/local/go/src/os/signal/signal_unix.go:29 +0x41

goroutine 26 [semacquire, 25 minutes]:
sync.runtime_Semacquire(0xc0004400d8)
    /usr/local/go/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc0004400d0)
    /usr/local/go/src/sync/waitgroup.go:130 +0x64
sigs.k8s.io/kind/pkg/errors.AggregateConcurrent(0xc0006a7760, 0x2, 0x2, 0x1cbc880, 0xc0000f4000)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/errors/concurrent.go:54 +0xff
sigs.k8s.io/kind/pkg/exec.RunWithStdoutReader(0x1cbc880, 0xc0000f4000, 0xc00022c000, 0x0, 0x0)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/exec/helpers.go:106 +0x1cc
sigs.k8s.io/kind/pkg/internal/cluster/logs.dumpDir(0x1cbcf80, 0x2a5c6f0, 0x1cb4900, 0xc0000864c0, 0x1a07718, 0x8, 0xc000150030, 0x27, 0x15fe516, 0x1841660)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/internal/cluster/logs/logs.go:132 +0x256
sigs.k8s.io/kind/pkg/internal/cluster/logs.Collect(0x1cbcf80, 0x2a5c6f0, 0xc0004d4010, 0x1, 0x1, 0xc0002b6160, 0x14, 0x0, 0x30)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/internal/cluster/logs/logs.go:76 +0x377
sigs.k8s.io/kind/pkg/cluster.(*Provider).CollectLogs(0xc0004b9700, 0x1a01ac6, 0x4, 0xc0002b6160, 0x14, 0xc0002b6160, 0x14)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/cluster/provider.go:147 +0xb9
github.com/kudobuilder/kudo/pkg/test.(*kind).CollectLogs(...)
    /home/porridge/Desktop/work/mesosphere/code/kudo/pkg/test/kind.go:81
github.com/kudobuilder/kudo/pkg/test.(*Harness).Stop(0xc00068ef00)
    /home/porridge/Desktop/work/mesosphere/code/kudo/pkg/test/harness.go:444 +0x75d
runtime.Goexit()
    /usr/local/go/src/runtime/panic.go:563 +0xec
testing.(*common).FailNow(0xc000395f00)
    /usr/local/go/src/testing/testing.go:653 +0x39
testing.(*common).Fatal(0xc000395f00, 0xc0006a7c80, 0x1, 0x1)
    /usr/local/go/src/testing/testing.go:710 +0x78
github.com/kudobuilder/kudo/pkg/test.(*Harness).Run(0xc00068ef00)
    /home/porridge/Desktop/work/mesosphere/code/kudo/pkg/test/harness.go:383 +0x1dc
github.com/kudobuilder/kudo/pkg/kudoctl/cmd.newTestCmd.func2.1(0xc000395f00)
    /home/porridge/Desktop/work/mesosphere/code/kudo/pkg/kudoctl/cmd/test.go:169 +0xd1
testing.tRunner(0xc000395f00, 0xc0002d5870)
    /usr/local/go/src/testing/testing.go:909 +0xc9
created by testing.(*T).Run
    /usr/local/go/src/testing/testing.go:960 +0x350

goroutine 29 [IO wait, 25 minutes]:
internal/poll.runtime_pollWait(0x7fd5f0544dd8, 0x72, 0xffffffffffffffff)
    /usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0004ca078, 0x72, 0x201, 0x200, 0xffffffffffffffff)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc0004ca060, 0xc00055e6e8, 0x200, 0x200, 0x0, 0x0, 0x0)
    /usr/local/go/src/internal/poll/fd_unix.go:169 +0x1cf
os.(*File).read(...)
    /usr/local/go/src/os/file_unix.go:259
os.(*File).Read(0xc000010070, 0xc00055e6e8, 0x200, 0x200, 0xc0001fc180, 0xc000081bb8, 0x47236a)
    /usr/local/go/src/os/file.go:116 +0x71
io.ReadAtLeast(0x1c71fe0, 0xc000010070, 0xc00055e6e8, 0x200, 0x200, 0x200, 0x1329d87, 0x1c735c0, 0x2a5c5b8)
    /usr/local/go/src/io/io.go:310 +0x87
io.ReadFull(...)
    /usr/local/go/src/io/io.go:329
archive/tar.(*Reader).readHeader(0xc00055e6c0, 0xc000010070, 0xc00055e6e8, 0x0, 0x200)
    /usr/local/go/src/archive/tar/reader.go:345 +0x78
archive/tar.(*Reader).next(0xc00055e6c0, 0x18ebe00, 0x43a101, 0xc00055e6c0)
    /usr/local/go/src/archive/tar/reader.go:77 +0x13b
archive/tar.(*Reader).Next(0xc00055e6c0, 0xc00055e6c0, 0x480430, 0x47df9a)
    /usr/local/go/src/archive/tar/reader.go:52 +0x42
sigs.k8s.io/kind/pkg/internal/cluster/logs.untar(0x1cbcf80, 0x2a5c6f0, 0x1c71fe0, 0xc000010070, 0xc000150030, 0x27, 0xc000470718, 0x4a2691)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/internal/cluster/logs/logs.go:144 +0xf3
sigs.k8s.io/kind/pkg/internal/cluster/logs.dumpDir.func1(0x1c71fe0, 0xc000010070, 0xc0002104d8, 0xc0000e0000)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/internal/cluster/logs/logs.go:133 +0x83
sigs.k8s.io/kind/pkg/exec.RunWithStdoutReader.func1(0xc000470770, 0xc000210480)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/exec/helpers.go:108 +0x3a
sigs.k8s.io/kind/pkg/errors.AggregateConcurrent.func1(0xc0004400d0, 0xc0004ca120, 0xc0004d8120)
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/errors/concurrent.go:51 +0x5b
created by sigs.k8s.io/kind/pkg/errors.AggregateConcurrent
    /home/porridge/go/pkg/mod/sigs.k8s.io/kind@v0.6.1/pkg/errors/concurrent.go:49 +0xd8

rax    0xfffffffffffffffc
rbx    0x3b985be3
rcx    0x463343
rdx    0x0
rdi    0x2a43dc0
rsi    0x80
rbp    0xc00006c6e8
rsp    0xc00006c6a0
r8     0x0
r9     0x0
r10    0xc00006c6d8
r11    0x202
r12    0x2
r13    0x7fd5f5887008
r14    0x4
r15    0x2f
rip    0x463343
rflags 0x202
cs     0x33
fs     0x0
gs     0x0
make: *** [Makefile:31: e2e-test] Błąd 2
zen-dog commented 4 years ago

@porridge did this behavior occur in the recent versions or can we close this issue (at leat for now)?

porridge commented 4 years ago

It never happened to me again. Looking at the stack traces now, it seems like kind was collecting logs at the point I killed it... We can re-open if it ever occurs again.