-
Type:
Bug
-
Resolution: Incomplete
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.4.4
-
Component/s: mongodump
-
Labels:None
I'm getting this intermittent stale behavior while using mongodump, where dump gets stale until the cursor is eventually deleted because it's idle in mongo router. I took a trace while mongodump was in this situation, hoping it can give an hint on what's going on. Usually this dump takes 8s.
be02-node-prd_axtract root@alfacsmbe02:~# mongodump --host localhost --port 27016 --db axtract --collection cpes --out - --username <myuser> --password <mypass> --authenticationDatabase admin | /opt/axtract/bin/ax.nocache --output test 2017-11-29T22:58:58.807+0000 writing axtract.cpes to stdout 2017-11-29T22:59:01.773+0000 [#############...........] axtract.cpes 5504/9932 (55.4%) 2017-11-29T22:59:04.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:07.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:10.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:13.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:16.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:19.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:22.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:25.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:28.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:31.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:34.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:37.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:40.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:43.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:46.772+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:49.773+0000 [####################....] axtract.cpes 8648/9932 (87.1%) 2017-11-29T22:59:52.773+0000 [####################....] axtract.cpes 8648/9932 (87.1%) SIGABRT: abort PC=0x463ff1 m=0 goroutine 0 [idle]: runtime.futex(0xdd1f70, 0x0, 0x0, 0x0, 0x0, 0xdd0e20, 0x0, 0x0, 0x7ffea16ef1f0, 0x417482, ...) /opt/go/src/runtime/sys_linux_amd64.s:387 +0x21 runtime.futexsleep(0xdd1f70, 0x0, 0xffffffffffffffff) /opt/go/src/runtime/os_linux.go:45 +0x62 runtime.notesleep(0xdd1f70) /opt/go/src/runtime/lock_futex.go:145 +0x82 runtime.stopm() /opt/go/src/runtime/proc.go:1594 +0xad runtime.findrunnable(0xc42001b500, 0x0) /opt/go/src/runtime/proc.go:2021 +0x228 runtime.schedule() /opt/go/src/runtime/proc.go:2120 +0x14c runtime.park_m(0xc420109040) /opt/go/src/runtime/proc.go:2183 +0x123 runtime.mcall(0x7ffea16ef390) /opt/go/src/runtime/asm_amd64.s:240 +0x5b goroutine 1 [chan receive]: github.com/mongodb/mongo-tools/mongodump.(*MongoDump).DumpIntents(0xc42015a000, 0x86ebd6, 0x22) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:497 +0x1d9 github.com/mongodb/mongo-tools/mongodump.(*MongoDump).Dump(0xc42015a000, 0x0, 0x0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:378 +0x550 main.main() /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/mongodump/main/mongodump.go:81 +0x519 goroutine 17 [syscall, locked to thread]: runtime.goexit() /opt/go/src/runtime/asm_amd64.s:2086 +0x1 goroutine 5 [syscall]: os/signal.signal_recv(0x0) /opt/go/src/runtime/sigqueue.go:116 +0x157 os/signal.loop() /opt/go/src/os/signal/signal_unix.go:22 +0x22 created by os/signal.init.1 /opt/go/src/os/signal/signal_unix.go:28 +0x41 goroutine 36 [select]: github.com/mongodb/mongo-tools/common/signals.handleSignals(0xc4200f7290, 0xc42010e2a0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/common/signals/signals.go:39 +0x5dd created by github.com/mongodb/mongo-tools/common/signals.HandleWithInterrupt /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/common/signals/signals.go:25 +0x67 goroutine 35 [select]: github.com/mongodb/mongo-tools/common/progress.(*BarWriter).start(0xc4200f24b0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/common/progress/manager.go:147 +0x155 created by github.com/mongodb/mongo-tools/common/progress.(*BarWriter).Start /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/common/progress/manager.go:136 +0x4c goroutine 37 [select]: gopkg.in/mgo%2ev2.(*mongoCluster).syncServersLoop(0xc420072300) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/cluster.go:394 +0x3b3 created by gopkg.in/mgo%2ev2.newCluster /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/cluster.go:78 +0x194 goroutine 19 [select, locked to thread]: runtime.gopark(0xa1b428, 0x0, 0x862b05, 0x6, 0x18, 0x2) /opt/go/src/runtime/proc.go:259 +0x13a runtime.selectgoImpl(0xc420026f30, 0x0, 0x18) /opt/go/src/runtime/select.go:423 +0x11d9 runtime.selectgo(0xc420026f30) /opt/go/src/runtime/select.go:238 +0x1c runtime.ensureSigM.func1() /opt/go/src/runtime/signal1_unix.go:304 +0x2f3 runtime.goexit() /opt/go/src/runtime/asm_amd64.s:2086 +0x1 goroutine 42 [sleep]: time.Sleep(0x37e11d600) /opt/go/src/runtime/time.go:59 +0xe1 gopkg.in/mgo%2ev2.(*mongoServer).pinger(0xc42010c1c0, 0xc42018e701) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/server.go:301 +0x286 created by gopkg.in/mgo%2ev2.newServer /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/server.go:89 +0x15f goroutine 44 [IO wait]: net.runtime_pollWait(0x7fa809326130, 0x72, 0x4) /opt/go/src/runtime/netpoll.go:160 +0x59 net.(*pollDesc).wait(0xc420194760, 0x72, 0xc4201c5d28, 0xc4200121e0) /opt/go/src/net/fd_poll_runtime.go:73 +0x38 net.(*pollDesc).waitRead(0xc420194760, 0xdb8560, 0xc4200121e0) /opt/go/src/net/fd_poll_runtime.go:78 +0x34 net.(*netFD).Read(0xc420194700, 0xc42019e000, 0x24, 0x24, 0x0, 0xdb8560, 0xc4200121e0) /opt/go/src/net/fd_unix.go:243 +0x1a1 net.(*conn).Read(0xc4200f8130, 0xc42019e000, 0x24, 0x24, 0x0, 0x0, 0x0) /opt/go/src/net/net.go:173 +0x70 gopkg.in/mgo%2ev2.fill(0xdbd800, 0xc4200f8130, 0xc42019e000, 0x24, 0x24, 0x0, 0xffdb62) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/socket.go:535 +0x53 gopkg.in/mgo%2ev2.(*mongoSocket).readLoop(0xc42010c2a0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/socket.go:551 +0x125 created by gopkg.in/mgo%2ev2.newSocket /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/socket.go:194 +0x278 goroutine 20 [chan receive]: github.com/mongodb/mongo-tools/mongodump.(*MongoDump).dumpIterToWriter(0xc42015a000, 0xc4201cc0f0, 0x7fa80929d248, 0xc4200ec108, 0xdbaa60, 0xc4200e9370, 0x4, 0xc4200e9380) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:670 +0xfb github.com/mongodb/mongo-tools/mongodump.(*MongoDump).dumpQueryToIntent(0xc42015a000, 0xc4200ef200, 0xc420106480, 0xdbaaa0, 0xc4200ec108, 0x0, 0x0, 0x0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:626 +0x449 github.com/mongodb/mongo-tools/mongodump.(*MongoDump).DumpIntent(0xc42015a000, 0xc420106480, 0xdbaaa0, 0xc4200ec108, 0x0, 0x0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:535 +0x101b github.com/mongodb/mongo-tools/mongodump.(*MongoDump).DumpIntents.func1(0xc42015a000, 0xc4201048a0, 0x0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:484 +0x15f created by github.com/mongodb/mongo-tools/mongodump.(*MongoDump).DumpIntents /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:492 +0x17f goroutine 21 [semacquire]: sync.runtime_notifyListWait(0xc4201cc108, 0x2) /opt/go/src/runtime/sema.go:267 +0x122 sync.(*Cond).Wait(0xc4201cc0f8) /opt/go/src/sync/cond.go:57 +0x80 gopkg.in/mgo%2ev2.(*Iter).Next(0xc4201cc0f0, 0x7e8040, 0xc4201983e0, 0xc420a55000) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/session.go:3704 +0x135 github.com/mongodb/mongo-tools/mongodump.(*MongoDump).dumpIterToWriter.func1(0xc42015a000, 0xc4200e9540, 0xc420104a20, 0xc4201cc0f0) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:654 +0xaf created by github.com/mongodb/mongo-tools/mongodump.(*MongoDump).dumpIterToWriter /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/.gopath/src/github.com/mongodb/mongo-tools/mongodump/mongodump.go:665 +0xbc goroutine 56 [IO wait]: net.runtime_pollWait(0x7fa809326070, 0x72, 0x6) /opt/go/src/runtime/netpoll.go:160 +0x59 net.(*pollDesc).wait(0xc4203004c0, 0x72, 0xc420169d58, 0xc4200121e0) /opt/go/src/net/fd_poll_runtime.go:73 +0x38 net.(*pollDesc).waitRead(0xc4203004c0, 0xdb8560, 0xc4200121e0) /opt/go/src/net/fd_poll_runtime.go:78 +0x34 net.(*netFD).Read(0xc420300460, 0xc42019e390, 0x24, 0x24, 0x0, 0xdb8560, 0xc4200121e0) /opt/go/src/net/fd_unix.go:243 +0x1a1 net.(*conn).Read(0xc4201a0008, 0xc42019e390, 0x24, 0x24, 0x0, 0x0, 0x0) /opt/go/src/net/net.go:173 +0x70 gopkg.in/mgo%2ev2.fill(0xdbd800, 0xc4201a0008, 0xc42019e390, 0x24, 0x24, 0x0, 0x11) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/socket.go:535 +0x53 gopkg.in/mgo%2ev2.(*mongoSocket).readLoop(0xc420306380) /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/socket.go:551 +0x125 created by gopkg.in/mgo%2ev2.newSocket /data/mci/910b12d5ecdbf2a40fac555629ec6520/src/src/mongo/gotools/vendor/src/gopkg.in/mgo.v2/socket.go:194 +0x278 rax 0xca rbx 0xdd1210 rcx 0xffffffffffffffff rdx 0x0 rdi 0xdd1f70 rsi 0x0 rbp 0x7ffea16ef1c0 rsp 0x7ffea16ef178 r8 0x0 r9 0x0 r10 0x0 r11 0x286 r12 0x3700 r13 0x3700 r14 0x2 r15 0xffc000 rip 0x463ff1 rflags 0x286 cs 0x33 fs 0x0 gs 0x0