vmware / go-vcloud-director

Golang SDK for VMware Cloud Director
Other
82 stars 75 forks source link

Timeout for long operations #82

Open auppunda opened 6 years ago

auppunda commented 6 years ago

Example: Triggered by running govcd tests

SIGQUIT: quit
PC=0x105be73 m=0 sigcode=0

goroutine 0 [idle]:
runtime.kevent(0x7fff00000004, 0x0, 0x0, 0x7fff5fbff0c0, 0x40, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/sys_darwin_amd64.s:621 +0x23
runtime.netpoll(0xc420034f01, 0xc420032a01)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/netpoll_kqueue.go:79 +0x14c
runtime.findrunnable(0xc420030500, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/proc.go:2397 +0x65b
runtime.schedule()
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/proc.go:2541 +0x13b
runtime.park_m(0xc420134a80)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/proc.go:2604 +0xb6
runtime.mcall(0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/asm_amd64.s:351 +0x5b

goroutine 1 [chan receive, 9 minutes]:
testing.(*T).Run(0xc42012a0f0, 0x1446d7e, 0x4, 0x14614f0, 0x1077bb6)
    /usr/local/Cellar/go/1.10.3/libexec/src/testing/testing.go:825 +0x301
testing.runTests.func1(0xc42012a000)
    /usr/local/Cellar/go/1.10.3/libexec/src/testing/testing.go:1063 +0x64
testing.tRunner(0xc42012a000, 0xc420065df8)
    /usr/local/Cellar/go/1.10.3/libexec/src/testing/testing.go:777 +0xd0
testing.runTests(0xc42010c500, 0x166c940, 0x3, 0x3, 0x10122b9)
    /usr/local/Cellar/go/1.10.3/libexec/src/testing/testing.go:1061 +0x2c4
testing.(*M).Run(0xc420126080, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/testing/testing.go:978 +0x171
main.main()
    _testmain.go:46 +0x151

goroutine 5 [chan receive, 3 minutes]:
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.(*suiteRunner).runTest(0xc420126100, 0xc420132230, 0xc42012a1e0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/check.go:819 +0x55
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.(*suiteRunner).run(0xc420126100, 0xc4200206e0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/check.go:624 +0xf2
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.Run(0x143f320, 0xc4200206e0, 0xc420070cc0, 0x0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/run.go:92 +0x4d
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.RunAll(0xc420070cc0, 0x0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/run.go:84 +0xa1
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.TestingT(0xc42012a0f0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/run.go:72 +0x368
github.com/vmware/go-vcloud-director/govcd.Test(0xc42012a0f0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/govcd/api_vcd_test.go:91 +0x2b
testing.tRunner(0xc42012a0f0, 0x14614f0)
    /usr/local/Cellar/go/1.10.3/libexec/src/testing/testing.go:777 +0xd0
created by testing.(*T).Run
    /usr/local/Cellar/go/1.10.3/libexec/src/testing/testing.go:824 +0x2e0

goroutine 6 [select, 3 minutes]:
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.(*resultTracker)._loopRoutine(0xc42012c120)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/check.go:470 +0xf5
created by github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.(*resultTracker).start
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/check.go:450 +0x3f

goroutine 30 [IO wait]:
internal/poll.runtime_pollWait(0x1b00ea0, 0x72, 0xc42019d760)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc420126818, 0x72, 0xffffffffffffff00, 0x1494460, 0x1639418)
    /usr/local/Cellar/go/1.10.3/libexec/src/internal/poll/fd_poll_runtime.go:85 +0x9b
internal/poll.(*pollDesc).waitRead(0xc420126818, 0xc42046a000, 0x4000, 0x4000)
    /usr/local/Cellar/go/1.10.3/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc420126800, 0xc42046a000, 0x4000, 0x4000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/internal/poll/fd_unix.go:157 +0x1dc
net.(*netFD).Read(0xc420126800, 0xc42046a000, 0x4000, 0x4000, 0x2d3, 0xc4202c2f70, 0x3)
    /usr/local/Cellar/go/1.10.3/libexec/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc42000e298, 0xc42046a000, 0x4000, 0x4000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/net/net.go:176 +0x6a
crypto/tls.(*block).readFromUntil(0xc4202be420, 0x1b00f70, 0xc42000e298, 0x5, 0xc42000e298, 0xc42019da90)
    /usr/local/Cellar/go/1.10.3/libexec/src/crypto/tls/conn.go:493 +0x96
crypto/tls.(*Conn).readRecord(0xc42009bc00, 0x1461d17, 0xc42009bd20, 0x1056b60)
    /usr/local/Cellar/go/1.10.3/libexec/src/crypto/tls/conn.go:595 +0xe0
crypto/tls.(*Conn).Read(0xc42009bc00, 0xc4201bb000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/crypto/tls/conn.go:1156 +0x100
net/http.(*persistConn).Read(0xc4200cb320, 0xc4201bb000, 0x1000, 0x1000, 0xc42019db98, 0x10055b5, 0xc4202e4000)
    /usr/local/Cellar/go/1.10.3/libexec/src/net/http/transport.go:1453 +0x136
bufio.(*Reader).fill(0xc4202d4480)
    /usr/local/Cellar/go/1.10.3/libexec/src/bufio/bufio.go:100 +0x11e
bufio.(*Reader).Peek(0xc4202d4480, 0x1, 0x0, 0x0, 0x1, 0xc4203644e0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/bufio/bufio.go:132 +0x3a
net/http.(*persistConn).readLoop(0xc4200cb320)
    /usr/local/Cellar/go/1.10.3/libexec/src/net/http/transport.go:1601 +0x185
created by net/http.(*Transport).dialConn
    /usr/local/Cellar/go/1.10.3/libexec/src/net/http/transport.go:1237 +0x95a

goroutine 31 [select]:
net/http.(*persistConn).writeLoop(0xc4200cb320)
    /usr/local/Cellar/go/1.10.3/libexec/src/net/http/transport.go:1822 +0x14b
created by net/http.(*Transport).dialConn
    /usr/local/Cellar/go/1.10.3/libexec/src/net/http/transport.go:1238 +0x97f

goroutine 48 [sleep]:
time.Sleep(0xb2d05e00)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/time.go:102 +0x166
github.com/vmware/go-vcloud-director/govcd.(*Task).WaitTaskCompletion(0xc42014fb30, 0x0, 0x0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/govcd/task.go:75 +0x41
github.com/vmware/go-vcloud-director/govcd.(*TestVCD).Test_Shutdown(0xc4200206e0, 0xc42012a3c0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/govcd/vapp_test.go:236 +0xf4
reflect.Value.call(0x143f320, 0xc4200206e0, 0x9613, 0x1446cc2, 0x4, 0xc42004ef70, 0x1, 0x1, 0x16918e0, 0x143e120, ...)
    /usr/local/Cellar/go/1.10.3/libexec/src/reflect/value.go:447 +0x969
reflect.Value.Call(0x143f320, 0xc4200206e0, 0x9613, 0xc4204bff70, 0x1, 0x1, 0x0, 0xc4204bff07, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/reflect/value.go:308 +0xa4
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1(0xc42012a3c0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/check.go:781 +0x575
github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1(0xc420126100, 0xc42012a3c0, 0xc42027ede0)
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/check.go:675 +0x7c
created by github.com/vmware/go-vcloud-director/vendor/gopkg.in/check%2ev1.(*suiteRunner).forkCall
    /Users/Uppundaa/go2/src/github.com/vmware/go-vcloud-director/vendor/gopkg.in/check.v1/check.go:672 +0x20c

rax    0x4
rbx    0x0
rcx    0x7fff5fbff050
rdx    0x0
rdi    0x4
rsi    0x0
rbp    0x7fff5fbff8c0
rsp    0x7fff5fbff050
r8     0x40
r9     0x0
r10    0x7fff5fbff0c0
r11    0x246
r12    0xc42014f188
r13    0x1
r14    0xc42008c9c0
r15    0x1
rip    0x105be73
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (10m0s).
exit status 2
datacharmer commented 6 years ago

Which operation was it? Could you try with logs enabled?

auppunda commented 6 years ago

So I have been getting this problem with deploy and undeploy for vapps. It doesn't happen a lot just happens from time to time.