Wait loops fail strongly during the middle of the run.
Sample log where wait loops fails with panic during pod deletion.
STEP: Saw pod success
Nov 16 04:55:30.916: INFO: Pod "powervs-volume-tester-lrzb8" satisfied condition "Succeeded or Failed"
Nov 16 04:55:30.916: INFO: deleting Pod "powervs-8087"/"powervs-volume-tester-lrzb8"
Nov 16 04:55:30.946: INFO: Pod powervs-volume-tester-lrzb8 has the following logs: hello world
STEP: Deleting pod powervs-volume-tester-lrzb8 in namespace powervs-8087
Nov 16 04:55:30.953: INFO: deleting PVC "powervs-8087"/"pvc-ptkfh"
Nov 16 04:55:30.953: INFO: Deleting PersistentVolumeClaim "pvc-ptkfh"
STEP: waiting for claim's PV "pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a" to be deleted
Nov 16 04:55:30.959: INFO: Waiting up to 10m0s for PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a to get deleted
Nov 16 04:55:30.965: INFO: PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a found and phase=Bound (5.471448ms)
Nov 16 04:55:35.967: INFO: PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a found and phase=Released (5.007921884s)
Nov 16 04:55:40.970: INFO: PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a found and phase=Released (10.010273399s)
Nov 16 04:55:45.972: INFO: PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a found and phase=Released (15.012465718s)
Nov 16 04:55:50.974: INFO: PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a found and phase=Released (20.014503456s)
Nov 16 04:55:55.976: INFO: PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a found and phase=Released (25.017004809s)
Nov 16 04:56:00.978: INFO: PersistentVolume pvc-dbba1694-77d6-48c4-8b22-0de03d0bac8a found and phase=Released (30.019080219s)
panic: test timed out after 10m0s
goroutine 438 [running]:
testing.(*M).startAlarm.func1()
/usr/lib/golang/src/testing/testing.go:1618 +0xcc
created by time.goFunc
/usr/lib/golang/src/time/sleep.go:167 +0x44
goroutine 1 [chan receive, 10 minutes]:
testing.(*T).Run(0xc000636900, 0x1163c9c0, 0x7, 0x11716118, 0x402)
/usr/lib/golang/src/testing/testing.go:1169 +0x280
testing.runTests.func1(0xc000636780)
/usr/lib/golang/src/testing/testing.go:1439 +0x78
testing.tRunner(0xc000636780, 0xc0008afd58)
/usr/lib/golang/src/testing/testing.go:1123 +0xd8
testing.runTests(0xc000584100, 0x12454de0, 0x1, 0x1, 0xc05cec5977367afe, 0x8bb9fce3f2, 0x1258cec0, 0x1258fb38)
/usr/lib/golang/src/testing/testing.go:1437 +0x2b4
testing.(*M).Run(0xc00000cd80, 0x0)
/usr/lib/golang/src/testing/testing.go:1345 +0x1a0
main.main()
_testmain.go:43 +0x130
goroutine 19 [chan receive]:
k8s.io/klog/v2.(*loggingT).flushDaemon(0x1258d400)
/root/go/pkg/mod/k8s.io/klog/[email protected]/klog.go:1169 +0x78
created by k8s.io/klog/v2.init.0
/root/go/pkg/mod/k8s.io/klog/[email protected]/klog.go:417 +0xe4
goroutine 24 [chan receive]:
github.com/golang/glog.(*loggingT).flushDaemon(0x1258d180)
/root/go/pkg/mod/github.com/golang/[email protected]/glog.go:882 +0x78
created by github.com/golang/glog.init.0
/root/go/pkg/mod/github.com/golang/[email protected]/glog.go:410 +0x2ac
goroutine 32 [IO wait]:
internal/poll.runtime_pollWait(0x7fff635e8e88, 0x72, 0xc0003b4005)
/usr/lib/golang/src/runtime/netpoll.go:222 +0x50
internal/poll.(*pollDesc).wait(0xc000976d18, 0x72, 0x11868400, 0x124843c0, 0x0)
/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:87 +0x40
internal/poll.(*pollDesc).waitRead(...)
/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000976d00, 0xc0003b4000, 0x382c, 0x382c, 0x0, 0x0, 0x0)
/usr/lib/golang/src/internal/poll/fd_unix.go:159 +0x184
net.(*netFD).Read(0xc000976d00, 0xc0003b4000, 0x382c, 0x382c, 0x0, 0x0, 0x1032d57c)
/usr/lib/golang/src/net/fd_posix.go:55 +0x48
net.(*conn).Read(0xc000632780, 0xc0003b4000, 0x382c, 0x382c, 0x0, 0x0, 0x0)
/usr/lib/golang/src/net/net.go:182 +0x84
crypto/tls.(*atLeastReader).Read(0xc0003acba0, 0xc0003b4000, 0x382c, 0x382c, 0x1032fa1c, 0x54c, 0xc00003c000)
/usr/lib/golang/src/crypto/tls/conn.go:779 +0x60
bytes.(*Buffer).ReadFrom(0xc00027e980, 0x1185fa00, 0xc0003acba0, 0xc0003b4005, 0x113f6c80, 0x115bfc40)
/usr/lib/golang/src/bytes/buffer.go:204 +0xac
crypto/tls.(*Conn).readFromUntil(0xc00027e700, 0x118669e0, 0xc000632780, 0x5, 0xc000632780, 0x54c)
/usr/lib/golang/src/crypto/tls/conn.go:801 +0xd4
crypto/tls.(*Conn).readRecordOrCCS(0xc00027e700, 0x0, 0x0, 0x18)
/usr/lib/golang/src/crypto/tls/conn.go:608 +0xf4
crypto/tls.(*Conn).readRecord(...)
/usr/lib/golang/src/crypto/tls/conn.go:576
crypto/tls.(*Conn).Read(0xc00027e700, 0xc0003a0000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/golang/src/crypto/tls/conn.go:1252 +0x150
bufio.(*Reader).Read(0xc00035b860, 0xc0008c8118, 0x9, 0x9, 0x11719d00, 0x1040c560, 0x11719d01)
/usr/lib/golang/src/bufio/bufio.go:227 +0x238
io.ReadAtLeast(0x1185f820, 0xc00035b860, 0xc0008c8118, 0x9, 0x9, 0x9, 0x0, 0x1185fc00, 0xc000118030)
/usr/lib/golang/src/io/io.go:314 +0x84
io.ReadFull(...)
/usr/lib/golang/src/io/io.go:333
golang.org/x/net/http2.readFrameHeader(0xc0008c8118, 0x9, 0x9, 0x1185f820, 0xc00035b860, 0x0, 0x0, 0xc000419770, 0x0)
/root/go/pkg/mod/golang.org/x/[email protected]/http2/frame.go:237 +0x60
golang.org/x/net/http2.(*Framer).ReadFrame(0xc0008c80e0, 0xc000419770, 0x0, 0x0, 0x0)
/root/go/pkg/mod/golang.org/x/[email protected]/http2/frame.go:492 +0x84
golang.org/x/net/http2.(*clientConnReadLoop).run(0xc00093ff98, 0x0, 0x0)
/root/go/pkg/mod/golang.org/x/[email protected]/http2/transport.go:1794 +0xc0
golang.org/x/net/http2.(*ClientConn).readLoop(0xc000448c00)
/root/go/pkg/mod/golang.org/x/[email protected]/http2/transport.go:1716 +0x68
created by golang.org/x/net/http2.(*Transport).newClientConn
/root/go/pkg/mod/golang.org/x/[email protected]/http2/transport.go:695 +0x554
goroutine 10 [sleep]:
time.Sleep(0x12a05f200)
/usr/lib/golang/src/runtime/time.go:188 +0xc4
k8s.io/kubernetes/test/e2e/framework/pv.WaitForPersistentVolumeDeleted(0x118cd6c0, 0xc000ac89a0, 0xc000ac63c0, 0x28, 0x12a05f200, 0x8bb2c97000, 0x4f, 0x0)
/root/go/pkg/mod/k8s.io/[email protected]/test/e2e/framework/pv/pv.go:832 +0xf8
github.com/ppc64le-cloud/powervs-csi-driver/tests/e2e/testsuites.(*TestPersistentVolumeClaim).Cleanup(0xc0003746c0)
/root/e2etest/powervs-csi-driver/tests/e2e/testsuites/testsuites.go:299 +0x2d0
github.com/ppc64le-cloud/powervs-csi-driver/tests/e2e/testsuites.(*DynamicallyProvisionedCmdVolumeTest).Run(0xc0009dd0d8, 0x118cd6c0, 0xc000ac89a0, 0xc000956b00)
/root/e2etest/powervs-csi-driver/tests/e2e/testsuites/dynamically_provisioned_cmd_volume_tester.go:29 +0x1f4
github.com/ppc64le-cloud/powervs-csi-driver/tests/e2e.glob..func1.2()
/root/e2etest/powervs-csi-driver/tests/e2e/dynamic_provisioning.go:60 +0x198
github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync(0xc0000a4ae0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/leafnodes/runner.go:113 +0xa0
github.com/onsi/ginkgo/internal/leafnodes.(*runner).run(0xc0000a4ae0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/leafnodes/runner.go:64 +0x170
github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run(0xc0003cd6e0, 0x11865220, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/leafnodes/it_node.go:26 +0x88
github.com/onsi/ginkgo/internal/spec.(*Spec).runSample(0xc00093c2d0, 0x0, 0x11865220, 0xc00005cac0)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/spec/spec.go:215 +0x21c
github.com/onsi/ginkgo/internal/spec.(*Spec).Run(0xc00093c2d0, 0x11865220, 0xc00005cac0)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/spec/spec.go:138 +0xf8
github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpec(0xc0006177c0, 0xc00093c2d0, 0x2)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:200 +0xec
github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs(0xc0006177c0, 0x1)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:170 +0x124
github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run(0xc0006177c0, 0xc000872970)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:66 +0x104
github.com/onsi/ginkgo/internal/suite.(*Suite).Run(0xc0003c0320, 0x7fff606afdc0, 0xc000636900, 0x1166c5d1, 0x24, 0xc000602060, 0x1, 0x1, 0x118ae9c0, 0xc00005cac0, ...)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/suite/suite.go:62 +0x364
github.com/onsi/ginkgo.RunSpecsWithCustomReporters(0x11867020, 0xc000636900, 0x1166c5d1, 0x24, 0xc000602050, 0x1, 0x1, 0x1)
/root/go/pkg/mod/github.com/onsi/[email protected]/ginkgo_dsl.go:226 +0x1d0
github.com/onsi/ginkgo.RunSpecsWithDefaultAndCustomReporters(0x11867020, 0xc000636900, 0x1166c5d1, 0x24, 0x0, 0x0, 0x0, 0x1006e84c)
/root/go/pkg/mod/github.com/onsi/[email protected]/ginkgo_dsl.go:214 +0x98
github.com/ppc64le-cloud/powervs-csi-driver/tests/e2e.TestE2E(0xc000636900)
/root/e2etest/powervs-csi-driver/tests/e2e/suite_test.go:59 +0x184
testing.tRunner(0xc000636900, 0x11716118)
/usr/lib/golang/src/testing/testing.go:1123 +0xd8
created by testing.(*T).Run
/usr/lib/golang/src/testing/testing.go:1168 +0x264
goroutine 11 [chan receive, 10 minutes]:
github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).registerForInterrupts(0xc0006177c0, 0xc000912fc0)
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:223 +0xbc
created by github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run
/root/go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:60 +0x78
goroutine 13 [syscall, 10 minutes]:
os/signal.signal_recv(0x0)
/usr/lib/golang/src/runtime/sigqueue.go:147 +0xf8
os/signal.loop()
/usr/lib/golang/src/os/signal/signal_unix.go:23 +0x24
created by os/signal.Notify.func1.1
/usr/lib/golang/src/os/signal/signal.go:150 +0x4c
exit status 2
FAIL github.com/ppc64le-cloud/powervs-csi-driver/tests/e2e 600.127s
[root@madhan-1-kube-1-22-2 e2e]#