Tokumx Crashes at 98% while building index on large collection

[adeelahmadch]

i have a very large collection :db.catalog_item.count()
112038199

and i am trying to build index on key { newItemExtQuoteId: 1 } , tokumx start the index and crashes at 98% without giving any proper error.
if i look into logs it says: Crash Reason: Got signal: 6 (Aborted). Error Logs is at the bottom.below the info for OS, TOKUMX Version and logs

TokumX Version

TokuMX mongod server v2.0.1-mongodb-2.4.10, using TokuKV rev 39fefcc4d2b1421ea09a9e41b130a64b230583b7
Wed Jun 3 23:49:31.430 git version: d454707

OS Version and Resources r3.large instance where nothing is running and 8GB assigned to TokuMX

cat /etc/os-release

NAME="Amazon Linux AMI"
VERSION="2015.03"
ID="amzn"
ID_LIKE="rhel fedora"
VERSION_ID="2015.03"
PRETTY_NAME="Amazon Linux AMI 2015.03"
ANSI_COLOR="0;33"
CPE_NAME="cpe:/o:amazon:linux:2015.03:ga"
HOME_URL="http://aws.amazon.com/amazon-linux-ami/"

ulimit -a

core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 122278
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 20000
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 122278
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

#########ERROR LOGS

you can see error after 98%

Wed Jun 3 11:07:01.797 [conn10] getmore vroozi.process query: { processState: "SUCCESS" } cursorid:11383450835057017 ntoreturn:0 keyUpdates:0 locks(micros) r:1389 nreturned:660 reslen:243118 1ms
Wed Jun 3 11:07:02.007 [conn8] Foreground index build progress (collect phase) for catalog.catalog_item, key { newItemExtQuoteId: 1 }: 110882000/112038199 98% (estimated documents)
Wed Jun 3 11:07:03.303
Wed Jun 3 11:07:03.305 ================================================================================
Wed Jun 3 11:07:03.305 Fatal error detected
Wed Jun 3 11:07:03.305 ================================================================================
Wed Jun 3 11:07:03.305
Wed Jun 3 11:07:03.305 About to gather debugging information, please include all of the following along
Wed Jun 3 11:07:03.305 with logs from other servers in the cluster in a bug report.
Wed Jun 3 11:07:03.305
Wed Jun 3 11:07:03.305 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.305 Version info:
Wed Jun 3 11:07:03.305
Wed Jun 3 11:07:03.305 tokumxVersion: 2.0.1
Wed Jun 3 11:07:03.305 gitVersion: d454707
Wed Jun 3 11:07:03.305 tokukvVersion: 39fefcc4d2b1421ea09a9e41b130a64b230583b7
Wed Jun 3 11:07:03.305 sysInfo: Linux 9df3ab53d071 3.11.0-26-generic #45-Ubuntu SMP Tue Jul 15 04:02:06 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux BOOST_LIB_VERSION=1_49
Wed Jun 3 11:07:03.305 loaderFlags:
Wed Jun 3 11:07:03.305 compilerFlags: -fPIC -fno-strict-aliasing -ggdb -Wall -Wsign-compare -Wno-unknown-pragmas -Winvalid-pch -pipe -Wnon-virtual-dtor -Woverloaded-virtual -Wno-unused-local-typedefs -fno-builtin-memcmp -O3
Wed Jun 3 11:07:03.305 debug: false
Wed Jun 3 11:07:03.305
Wed Jun 3 11:07:03.305 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.305 Simple stacktrace:
Wed Jun 3 11:07:03.305
0xc4dfe3 0x951e37 0x9552cb 0x776c77 0x7fb3c9da5640 0x7fb3c9da55c9 0x7fb3c9da6cd8 0x7fb3cb4143f7 0x7fb3cb3f5f63 0x7fb3cb3ffd8b 0x7fb3cb4158ae 0x7fb3cb416bf5 0x7fb3cb416ce0 0x7fb3cb416ce0 0x7fb3cb416ce0 0x7fb3cb418620 0x7fb3cb42eaf4 0x9acfb5 0x9af190 0x9b12d8
/usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x23) [0xc4dfe3]
/usr/bin/mongod() [0x951e37]
/usr/bin/mongod(_ZN5mongo13dumpCrashInfoERKNS_10StringDataE+0x2b) [0x9552cb]
/usr/bin/mongod(_ZN5mongo10abruptQuitEi+0xa7) [0x776c77]
/lib64/libc.so.6(+0x35640) [0x7fb3c9da5640]
/lib64/libc.so.6(gsignal+0x39) [0x7fb3c9da55c9]
/lib64/libc.so.6(abort+0x148) [0x7fb3c9da6cd8]
/usr/lib64/tokumx/libtokufractaltree.so(+0x7e3f7) [0x7fb3cb4143f7]
/usr/lib64/tokumx/libtokufractaltree.so(+0x5ff63) [0x7fb3cb3f5f63]
/usr/lib64/tokumx/libtokufractaltree.so(+0x69d8b) [0x7fb3cb3ffd8b]
/usr/lib64/tokumx/libtokufractaltree.so(+0x7f8ae) [0x7fb3cb4158ae]
/usr/lib64/tokumx/libtokufractaltree.so(+0x80bf5) [0x7fb3cb416bf5]
/usr/lib64/tokumx/libtokufractaltree.so(+0x80ce0) [0x7fb3cb416ce0]
/usr/lib64/tokumx/libtokufractaltree.so(+0x80ce0) [0x7fb3cb416ce0]
/usr/lib64/tokumx/libtokufractaltree.so(+0x80ce0) [0x7fb3cb416ce0]
/usr/lib64/tokumx/libtokufractaltree.so(+0x82620) [0x7fb3cb418620]
/usr/lib64/tokumx/libtokufractaltree.so(+0x98af4) [0x7fb3cb42eaf4]
/usr/bin/mongod(_ZN5mongo11IndexCursor13fetchMoreRowsEv+0xb5) [0x9acfb5]
/usr/bin/mongod(_ZN5mongo11IndexCursor8_advanceEv+0x60) [0x9af190]
/usr/bin/mongod(_ZN5mongo11IndexCursor7advanceEv+0x88) [0x9b12d8]
Wed Jun 3 11:07:03.384
Wed Jun 3 11:07:03.384 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.384 TokuKV engine backtrace:
Wed Jun 3 11:07:03.384
Wed Jun 3 11:07:03.392 Backtrace: (Note: toku_do_assert=0x0x7fb3cb18f860)

Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokuportability.so(Z27db_env_do_backtrace_errfuncPFvPKviPKczES0+0x1f) [0x7fb3cb19156f]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x1439d) [0x7fb3cb3aa39d]
Wed Jun 3 11:07:03.406 /usr/bin/mongod() [0x951f08]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo13dumpCrashInfoERKNS_10StringDataE+0x2b) [0x9552cb]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo10abruptQuitEi+0xa7) [0x776c77]
Wed Jun 3 11:07:03.406 /lib64/libc.so.6(+0x35640) [0x7fb3c9da5640]
Wed Jun 3 11:07:03.406 /lib64/libc.so.6(gsignal+0x39) [0x7fb3c9da55c9]
Wed Jun 3 11:07:03.406 /lib64/libc.so.6(abort+0x148) [0x7fb3c9da6cd8]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x7e3f7) [0x7fb3cb4143f7]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x5ff63) [0x7fb3cb3f5f63]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x69d8b) [0x7fb3cb3ffd8b]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x7f8ae) [0x7fb3cb4158ae]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x80bf5) [0x7fb3cb416bf5]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x80ce0) [0x7fb3cb416ce0]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x80ce0) [0x7fb3cb416ce0]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x80ce0) [0x7fb3cb416ce0]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x82620) [0x7fb3cb418620]
Wed Jun 3 11:07:03.406 /usr/lib64/tokumx/libtokufractaltree.so(+0x98af4) [0x7fb3cb42eaf4]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo11IndexCursor13fetchMoreRowsEv+0xb5) [0x9acfb5]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo11IndexCursor8_advanceEv+0x60) [0x9af190]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo11IndexCursor7advanceEv+0x88) [0x9b12d8]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo14CollectionBase11ColdIndexer5buildEv+0x549) [0x948659]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo14CollectionBase11createIndexERKNS_7BSONObjE+0xb2) [0x9cae32]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo14CollectionBase11ensureIndexERKNS_7BSONObjE+0x167) [0x9cc287]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo10Collection11ensureIndexERKNS_7BSONObjE+0xbc) [0x9e6f6c]
Wed Jun 3 11:07:03.406 /usr/bin/mongod(_ZN5mongo13insertObjectsEPKcRKSt6vectorINS_7BSONObjESaIS3_EEbmbb+0x3dc) [0x9c89ac]
Wed Jun 3 11:07:03.407 /usr/bin/mongod() [0x98b006]
Wed Jun 3 11:07:03.407 /usr/bin/mongod(_ZN5mongo14receivedInsertERNS_7MessageERNS_5CurOpE+0x1315) [0x992545]
Wed Jun 3 11:07:03.407 /usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xe8b) [0x99345b]
Wed Jun 3 11:07:03.407 /usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x8b) [0x78cd0b]
Wed Jun 3 11:07:03.407 /usr/bin/mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x3dc) [0x895afc]
Wed Jun 3 11:07:03.407 /lib64/libpthread.so.0(+0x7df3) [0x7fb3cad72df3]
Wed Jun 3 11:07:03.407 /lib64/libc.so.6(clone+0x6d) [0x7fb3c9e661ad]
Wed Jun 3 11:07:03.407 BUILD_ID = 0
Wed Jun 3 11:07:03.409 time of environment creation: Sat Aug 16 23:00:21 2014
Wed Jun 3 11:07:03.409 time of engine startup: Wed Jun 3 10:21:52 2015
Wed Jun 3 11:07:03.409 time now: Wed Jun 3 11:07:03 2015
Wed Jun 3 11:07:03.409 db opens: 304
Wed Jun 3 11:07:03.409 db closes: 163
Wed Jun 3 11:07:03.409 num open dbs now: 141
Wed Jun 3 11:07:03.409 max open dbs: 141
Wed Jun 3 11:07:03.409 period, in ms, that recovery log is automatically fsynced: 100
Wed Jun 3 11:07:03.409 dictionary inserts: 26
Wed Jun 3 11:07:03.410 dictionary inserts fail: 0
Wed Jun 3 11:07:03.410 dictionary deletes: 0
Wed Jun 3 11:07:03.410 dictionary deletes fail: 0
Wed Jun 3 11:07:03.410 dictionary updates: 9
Wed Jun 3 11:07:03.410 dictionary updates fail: 0
Wed Jun 3 11:07:03.410 dictionary broadcast updates: 0
Wed Jun 3 11:07:03.410 dictionary broadcast updates fail: 0
Wed Jun 3 11:07:03.410 dictionary multi inserts: 23
Wed Jun 3 11:07:03.410 dictionary multi inserts fail: 0
Wed Jun 3 11:07:03.410 dictionary multi deletes: 0
Wed Jun 3 11:07:03.410 dictionary multi deletes fail: 0
Wed Jun 3 11:07:03.410 dictionary updates multi: 3
Wed Jun 3 11:07:03.410 dictionary updates multi fail: 0
Wed Jun 3 11:07:03.410 le: max committed xr: 1
Wed Jun 3 11:07:03.410 le: max provisional xr: 2
Wed Jun 3 11:07:03.410 le: expanded: 0
Wed Jun 3 11:07:03.410 le: max memsize: 12556
Wed Jun 3 11:07:03.410 le: size of leafentries before garbage collection (during message application): 187281
Wed Jun 3 11:07:03.410 le: size of leafentries after garbage collection (during message application): 90409
Wed Jun 3 11:07:03.410 le: size of leafentries before garbage collection (outside message application): 0
Wed Jun 3 11:07:03.410 le: size of leafentries after garbage collection (outside message application): 0
Wed Jun 3 11:07:03.410 checkpoint: period: 60
Wed Jun 3 11:07:03.410 checkpoint: footprint: 0
Wed Jun 3 11:07:03.410 checkpoint: last checkpoint began : Wed Jun 3 11:06:52 2015
Wed Jun 3 11:07:03.410 checkpoint: last complete checkpoint began : Wed Jun 3 11:06:52 2015
Wed Jun 3 11:07:03.410 checkpoint: last complete checkpoint ended: Wed Jun 3 11:06:53 2015
Wed Jun 3 11:07:03.410 checkpoint: time spent during checkpoint (begin and end phases): 29
Wed Jun 3 11:07:03.410 checkpoint: time spent during last checkpoint (begin and end phases): 1
Wed Jun 3 11:07:03.410 checkpoint: last complete checkpoint LSN: 820627372
Wed Jun 3 11:07:03.410 checkpoint: checkpoints taken : 46
Wed Jun 3 11:07:03.410 checkpoint: checkpoints failed: 0
Wed Jun 3 11:07:03.410 checkpoint: waiters now: 0
Wed Jun 3 11:07:03.410 checkpoint: waiters max: 0
Wed Jun 3 11:07:03.410 checkpoint: non-checkpoint client wait on mo lock: 0
Wed Jun 3 11:07:03.410 checkpoint: non-checkpoint client wait on cs lock: 0
Wed Jun 3 11:07:03.410 checkpoint: checkpoint begin time: 70300
Wed Jun 3 11:07:03.410 checkpoint: long checkpoint begin time: 0
Wed Jun 3 11:07:03.410 checkpoint: long checkpoint begin count: 0
Wed Jun 3 11:07:03.410 cachetable: miss: 9758
Wed Jun 3 11:07:03.410 cachetable: miss time: 33133243
Wed Jun 3 11:07:03.410 cachetable: prefetches: 50115
Wed Jun 3 11:07:03.410 cachetable: size current: 5486165566
Wed Jun 3 11:07:03.410 cachetable: size limit: 5905580032
Wed Jun 3 11:07:03.410 cachetable: size writing: 0
Wed Jun 3 11:07:03.410 cachetable: size nonleaf: 91252734
Wed Jun 3 11:07:03.410 cachetable: size leaf: 5290051696
Wed Jun 3 11:07:03.410 cachetable: size rollback: 3536
Wed Jun 3 11:07:03.410 cachetable: size cachepressure: 66852458
Wed Jun 3 11:07:03.410 cachetable: size currently cloned data for checkpoint: 0
Wed Jun 3 11:07:03.410 cachetable: evictions: 81
Wed Jun 3 11:07:03.410 cachetable: cleaner executions: 1399
Wed Jun 3 11:07:03.410 cachetable: cleaner period: 2
Wed Jun 3 11:07:03.410 cachetable: cleaner iterations: 5
Wed Jun 3 11:07:03.410 cachetable: number of waits on cache pressure: 0
Wed Jun 3 11:07:03.410 cachetable: time waiting on cache pressure: 0
Wed Jun 3 11:07:03.410 cachetable: number of long waits on cache pressure: 0
Wed Jun 3 11:07:03.410 cachetable: long time waiting on cache pressure: 0
Wed Jun 3 11:07:03.410 locktree: memory size: 516
Wed Jun 3 11:07:03.410 locktree: memory size limit: 536870912
Wed Jun 3 11:07:03.410 locktree: number of times lock escalation ran: 0
Wed Jun 3 11:07:03.410 locktree: time spent running escalation (seconds): 0.000000
Wed Jun 3 11:07:03.410 locktree: latest post-escalation memory size: 0
Wed Jun 3 11:07:03.410 locktree: number of locktrees open now: 143
Wed Jun 3 11:07:03.410 locktree: number of pending lock requests: 0
Wed Jun 3 11:07:03.411 locktree: number of locktrees eligible for the STO: 2
Wed Jun 3 11:07:03.411 locktree: number of times a locktree ended the STO early: 1
Wed Jun 3 11:07:03.411 locktree: time spent ending the STO early (seconds): 0.000017
Wed Jun 3 11:07:03.411 locktree: number of wait locks: 0
Wed Jun 3 11:07:03.411 locktree: time waiting for locks: 0
Wed Jun 3 11:07:03.411 locktree: number of long wait locks: 0
Wed Jun 3 11:07:03.411 locktree: long time waiting for locks: 0
Wed Jun 3 11:07:03.411 locktree: number of lock timeouts: 0
Wed Jun 3 11:07:03.411 locktree: number of waits on lock escalation: 0
Wed Jun 3 11:07:03.411 locktree: time waiting on lock escalation: 0
Wed Jun 3 11:07:03.411 locktree: number of long waits on lock escalation: 0
Wed Jun 3 11:07:03.411 locktree: long time waiting on lock escalation: 0
Wed Jun 3 11:07:03.411 ft: dictionary updates: 350518
Wed Jun 3 11:07:03.411 ft: dictionary broadcast updates: 0
Wed Jun 3 11:07:03.411 ft: descriptor set: 133
Wed Jun 3 11:07:03.411 ft: messages ignored by leaf due to msn: 30672
Wed Jun 3 11:07:03.411 ft: total search retries due to TRY_AGAIN: 12393
Wed Jun 3 11:07:03.411 ft: searches requiring more tries than the height of the tree: 6
Wed Jun 3 11:07:03.411 ft: searches requiring more tries than the height of the tree plus three: 5
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (not for checkpoint): 8
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (not for checkpoint) (bytes): 178688
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (not for checkpoint) (uncompressed bytes): 1491732
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (not for checkpoint) (seconds): 0.000165
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (not for checkpoint): 0
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (not for checkpoint) (bytes): 0
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (not for checkpoint) (uncompressed bytes): 0
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (not for checkpoint) (seconds): 0.000000
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (for checkpoint): 57
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (for checkpoint) (bytes): 13592576
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (for checkpoint) (uncompressed bytes): 71382557
Wed Jun 3 11:07:03.411 ft: leaf nodes flushed to disk (for checkpoint) (seconds): 0.007093
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (for checkpoint): 46
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (for checkpoint) (bytes): 184832
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (for checkpoint) (uncompressed bytes): 1369733
Wed Jun 3 11:07:03.411 ft: nonleaf nodes flushed to disk (for checkpoint) (seconds): 0.011195
Wed Jun 3 11:07:03.411 ft: uncompressed / compressed bytes written (leaf): UNKNOWN STATUS TYPE: 6
Wed Jun 3 11:07:03.411 ft: uncompressed / compressed bytes written (nonleaf): UNKNOWN STATUS TYPE: 6
Wed Jun 3 11:07:03.411 ft: uncompressed / compressed bytes written (overall): UNKNOWN STATUS TYPE: 6
Wed Jun 3 11:07:03.411 ft: nonleaf node partial evictions: 82
Wed Jun 3 11:07:03.411 ft: nonleaf node partial evictions (bytes): 1755376
Wed Jun 3 11:07:03.411 ft: leaf node partial evictions: 2613937
Wed Jun 3 11:07:03.411 ft: leaf node partial evictions (bytes): 174577076805
Wed Jun 3 11:07:03.411 ft: leaf node full evictions: 11
Wed Jun 3 11:07:03.411 ft: leaf node full evictions (bytes): 4390470
Wed Jun 3 11:07:03.411 ft: nonleaf node full evictions: 70
Wed Jun 3 11:07:03.411 ft: nonleaf node full evictions (bytes): 106320195
Wed Jun 3 11:07:03.411 ft: leaf nodes created: 18
Wed Jun 3 11:07:03.411 ft: nonleaf nodes created: 0
Wed Jun 3 11:07:03.411 ft: leaf nodes destroyed: 0
Wed Jun 3 11:07:03.411 ft: nonleaf nodes destroyed: 0
Wed Jun 3 11:07:03.411 ft: bytes of messages injected at root (all trees): 0
Wed Jun 3 11:07:03.411 ft: bytes of messages flushed from h1 nodes to leaves: 104424
Wed Jun 3 11:07:03.411 ft: bytes of messages currently in trees (estimate): 18446744073709447192
Wed Jun 3 11:07:03.411 ft: messages injected at root: 0
Wed Jun 3 11:07:03.411 ft: broadcast messages injected at root: 0
Wed Jun 3 11:07:03.411 ft: basements decompressed as a target of a query: 0
Wed Jun 3 11:07:03.411 ft: basements decompressed for prelocked range: 0
Wed Jun 3 11:07:03.411 ft: basements decompressed for prefetch: 0
Wed Jun 3 11:07:03.411 ft: basements decompressed for write: 0
Wed Jun 3 11:07:03.411 ft: buffers decompressed as a target of a query: 5
Wed Jun 3 11:07:03.411 ft: buffers decompressed for prelocked range: 25
Wed Jun 3 11:07:03.411 ft: buffers decompressed for prefetch: 0
Wed Jun 3 11:07:03.411 ft: buffers decompressed for write: 45
Wed Jun 3 11:07:03.412 ft: pivots fetched for query: 4565
Wed Jun 3 11:07:03.412 ft: pivots fetched for query (bytes): 149541888
Wed Jun 3 11:07:03.412 ft: pivots fetched for query (seconds): 1.895513
Wed Jun 3 11:07:03.412 ft: pivots fetched for prefetch: 50115
Wed Jun 3 11:07:03.412 ft: pivots fetched for prefetch (bytes): 1642138112
Wed Jun 3 11:07:03.412 ft: pivots fetched for prefetch (seconds): 18.704313
Wed Jun 3 11:07:03.412 ft: pivots fetched for write: 1
Wed Jun 3 11:07:03.412 ft: pivots fetched for write (bytes): 512
Wed Jun 3 11:07:03.412 ft: pivots fetched for write (seconds): 0.000001
Wed Jun 3 11:07:03.412 ft: basements fetched as a target of a query: 4812
Wed Jun 3 11:07:03.412 ft: basements fetched as a target of a query (bytes): 24135168
Wed Jun 3 11:07:03.412 ft: basements fetched as a target of a query (seconds): 0.015144
Wed Jun 3 11:07:03.412 ft: basements fetched for prelocked range: 233282
Wed Jun 3 11:07:03.412 ft: basements fetched for prelocked range (bytes): 1120098816
Wed Jun 3 11:07:03.412 ft: basements fetched for prelocked range (seconds): 4.180713
Wed Jun 3 11:07:03.412 ft: basements fetched for prefetch: 2481886
Wed Jun 3 11:07:03.412 ft: basements fetched for prefetch (bytes): 11944488960
Wed Jun 3 11:07:03.412 ft: basements fetched for prefetch (seconds): 40.789658
Wed Jun 3 11:07:03.412 ft: basements fetched for write: 798
Wed Jun 3 11:07:03.412 ft: basements fetched for write (bytes): 10586112
Wed Jun 3 11:07:03.412 ft: basements fetched for write (seconds): 0.003046
Wed Jun 3 11:07:03.412 ft: buffers fetched as a target of a query: 0
Wed Jun 3 11:07:03.412 ft: buffers fetched as a target of a query (bytes): 0
Wed Jun 3 11:07:03.412 ft: buffers fetched as a target of a query (seconds): 0.000000
Wed Jun 3 11:07:03.412 ft: buffers fetched for prelocked range: 0
Wed Jun 3 11:07:03.412 ft: buffers fetched for prelocked range (bytes): 0
Wed Jun 3 11:07:03.412 ft: buffers fetched for prelocked range (seconds): 0.000000
Wed Jun 3 11:07:03.412 ft: buffers fetched for prefetch: 0
Wed Jun 3 11:07:03.412 ft: buffers fetched for prefetch (bytes): 0
Wed Jun 3 11:07:03.412 ft: buffers fetched for prefetch (seconds): 0.000000
Wed Jun 3 11:07:03.412 ft: buffers fetched for write: 21
Wed Jun 3 11:07:03.412 ft: buffers fetched for write (bytes): 43520
Wed Jun 3 11:07:03.412 ft: buffers fetched for write (seconds): 0.000026
Wed Jun 3 11:07:03.412 ft: leaf compression to memory (seconds): 1.512713
Wed Jun 3 11:07:03.412 ft: leaf serialization to memory (seconds): 0.059871
Wed Jun 3 11:07:03.412 ft: leaf decompression to memory (seconds): 307.139583
Wed Jun 3 11:07:03.412 ft: leaf deserialization to memory (seconds): 60.891743
Wed Jun 3 11:07:03.412 ft: nonleaf compression to memory (seconds): 0.073413
Wed Jun 3 11:07:03.412 ft: nonleaf serialization to memory (seconds): 0.001956
Wed Jun 3 11:07:03.412 ft: nonleaf decompression to memory (seconds): 0.449442
Wed Jun 3 11:07:03.412 ft: nonleaf deserialization to memory (seconds): 0.257406
Wed Jun 3 11:07:03.412 ft: promotion: roots split: 0
Wed Jun 3 11:07:03.412 ft: promotion: leaf roots injected into: 56
Wed Jun 3 11:07:03.412 ft: promotion: h1 roots injected into: 0
Wed Jun 3 11:07:03.412 ft: promotion: injections at depth 0: 0
Wed Jun 3 11:07:03.412 ft: promotion: injections at depth 1: 9
Wed Jun 3 11:07:03.412 ft: promotion: injections at depth 2: 2
Wed Jun 3 11:07:03.412 ft: promotion: injections at depth 3: 0
Wed Jun 3 11:07:03.412 ft: promotion: injections lower than depth 3: 0
Wed Jun 3 11:07:03.412 ft: promotion: stopped because of a nonempty buffer: 0
Wed Jun 3 11:07:03.412 ft: promotion: stopped at height 1: 0
Wed Jun 3 11:07:03.412 ft: promotion: stopped because the child was locked or not at all in memory: 0
Wed Jun 3 11:07:03.412 ft: promotion: stopped because the child was not fully in memory: 0
Wed Jun 3 11:07:03.412 ft: promotion: stopped anyway, after locking the child: 0
Wed Jun 3 11:07:03.412 ft: basement nodes deserialized with fixed-keysize: 2720623
Wed Jun 3 11:07:03.412 ft: basement nodes deserialized with variable-keysize: 298
Wed Jun 3 11:07:03.412 ft: promotion: succeeded in using the rightmost leaf shortcut: 0
Wed Jun 3 11:07:03.412 ft: promotion: tried the rightmost leaf shorcut but failed (out-of-bounds): 0
Wed Jun 3 11:07:03.412 ft: promotion: tried the rightmost leaf shorcut but failed (child reactive): 0
Wed Jun 3 11:07:03.412 ft flusher: total nodes potentially flushed by cleaner thread: 44
Wed Jun 3 11:07:03.413 ft flusher: height-one nodes flushed by cleaner thread: 39
Wed Jun 3 11:07:03.413 ft flusher: height-greater-than-one nodes flushed by cleaner thread: 5
Wed Jun 3 11:07:03.413 ft flusher: nodes cleaned which had empty buffers: 0
Wed Jun 3 11:07:03.413 ft flusher: nodes dirtied by cleaner thread: 85
Wed Jun 3 11:07:03.413 ft flusher: max bytes in a buffer flushed by cleaner thread: 205102
Wed Jun 3 11:07:03.413 ft flusher: min bytes in a buffer flushed by cleaner thread: 198
Wed Jun 3 11:07:03.413 ft flusher: total bytes in buffers flushed by cleaner thread: 394922
Wed Jun 3 11:07:03.413 ft flusher: max workdone in a buffer flushed by cleaner thread: 85918
Wed Jun 3 11:07:03.413 ft flusher: min workdone in a buffer flushed by cleaner thread: 0
Wed Jun 3 11:07:03.413 ft flusher: total workdone in buffers flushed by cleaner thread: 373823
Wed Jun 3 11:07:03.413 ft flusher: times cleaner thread tries to merge a leaf: 0
Wed Jun 3 11:07:03.413 ft flusher: cleaner thread leaf merges in progress: 0
Wed Jun 3 11:07:03.413 ft flusher: cleaner thread leaf merges successful: 0
Wed Jun 3 11:07:03.413 ft flusher: nodes dirtied by cleaner thread leaf merges: 0
Wed Jun 3 11:07:03.413 ft flusher: total number of flushes done by flusher threads or cleaner threads: 44
Wed Jun 3 11:07:03.413 ft flusher: number of in memory flushes: 44
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that read something off disk: 0
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that triggered another flush in child: 0
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that triggered 1 cascading flush: 0
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that triggered 2 cascading flushes: 0
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that triggered 3 cascading flushes: 0
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that triggered 4 cascading flushes: 0
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that triggered 5 cascading flushes: 0
Wed Jun 3 11:07:03.413 ft flusher: number of flushes that triggered over 5 cascading flushes: 0
Wed Jun 3 11:07:03.413 ft flusher: leaf node splits: 0
Wed Jun 3 11:07:03.413 ft flusher: nonleaf node splits: 0
Wed Jun 3 11:07:03.413 ft flusher: leaf node merges: 0
Wed Jun 3 11:07:03.413 ft flusher: nonleaf node merges: 0
Wed Jun 3 11:07:03.413 ft flusher: leaf node balances: 0
Wed Jun 3 11:07:03.413 hot: operations ever started: 0
Wed Jun 3 11:07:03.413 hot: operations successfully completed: 0
Wed Jun 3 11:07:03.413 hot: operations aborted: 0
Wed Jun 3 11:07:03.413 hot: max number of flushes from root ever required to optimize a tree: 0
Wed Jun 3 11:07:03.413 txn: begin: 1752
Wed Jun 3 11:07:03.413 txn: begin read only: 3592
Wed Jun 3 11:07:03.413 txn: successful commits: 3971
Wed Jun 3 11:07:03.413 txn: aborts: 1372
Wed Jun 3 11:07:03.413 logger: next LSN: 820627518
Wed Jun 3 11:07:03.413 logger: writes: 230
Wed Jun 3 11:07:03.413 logger: writes (bytes): 588159
Wed Jun 3 11:07:03.413 logger: writes (uncompressed bytes): 588159
Wed Jun 3 11:07:03.413 logger: writes (seconds): 0.004663
Wed Jun 3 11:07:03.413 logger: number of long logger write operations: 0
Wed Jun 3 11:07:03.413 indexer: number of indexers successfully created: 0
Wed Jun 3 11:07:03.413 indexer: number of calls to toku_indexer_create_indexer() that failed: 0
Wed Jun 3 11:07:03.413 indexer: number of calls to indexer->build() succeeded: 0
Wed Jun 3 11:07:03.413 indexer: number of calls to indexer->build() failed: 0
Wed Jun 3 11:07:03.413 indexer: number of calls to indexer->close() that succeeded: 0
Wed Jun 3 11:07:03.413 indexer: number of calls to indexer->close() that failed: 0
Wed Jun 3 11:07:03.413 indexer: number of calls to indexer->abort(): 0
Wed Jun 3 11:07:03.413 indexer: number of indexers currently in existence: 0
Wed Jun 3 11:07:03.413 indexer: max number of indexers that ever existed simultaneously: 0
Wed Jun 3 11:07:03.413 loader: number of loaders successfully created: 7
Wed Jun 3 11:07:03.413 loader: number of calls to toku_loader_create_loader() that failed: 0
Wed Jun 3 11:07:03.413 loader: number of calls to loader->put() succeeded: 111107037
Wed Jun 3 11:07:03.413 loader: number of calls to loader->put() failed: 0
Wed Jun 3 11:07:03.413 loader: number of calls to loader->close() that succeeded: 6
Wed Jun 3 11:07:03.413 loader: number of calls to loader->close() that failed: 0
Wed Jun 3 11:07:03.413 loader: number of calls to loader->abort(): 0
Wed Jun 3 11:07:03.413 loader: number of loaders currently in existence: 1
Wed Jun 3 11:07:03.413 loader: max number of loaders that ever existed simultaneously: 1
Wed Jun 3 11:07:03.413 memory: number of malloc operations: 0
Wed Jun 3 11:07:03.413 memory: number of free operations: 0
Wed Jun 3 11:07:03.413 memory: number of realloc operations: 0
Wed Jun 3 11:07:03.414 memory: number of malloc operations that failed: 0
Wed Jun 3 11:07:03.414 memory: number of realloc operations that failed: 0
Wed Jun 3 11:07:03.414 memory: number of bytes requested: 0
Wed Jun 3 11:07:03.414 memory: number of bytes used (requested + overhead): 0
Wed Jun 3 11:07:03.414 memory: number of bytes freed: 0
Wed Jun 3 11:07:03.414 memory: largest attempted allocation size: 0
Wed Jun 3 11:07:03.414 memory: size of the last failed allocation attempt: 0
Wed Jun 3 11:07:03.414 memory: estimated maximum memory footprint: 0
Wed Jun 3 11:07:03.414 memory: mallocator version: tokumx-2.0.1-0-gd4547074dcc9129f2e13ed6b76fd78edb0a2828e
Wed Jun 3 11:07:03.414 memory: mmap threshold: 4194304
Wed Jun 3 11:07:03.414 filesystem: ENOSPC redzone state: 0
Wed Jun 3 11:07:03.414 filesystem: threads currently blocked by full disk: 0
Wed Jun 3 11:07:03.414 filesystem: number of operations rejected by enospc prevention (red zone): 0
Wed Jun 3 11:07:03.414 filesystem: most recent disk full: Wed Dec 31 16:00:00 1969
Wed Jun 3 11:07:03.414 filesystem: number of write operations that returned ENOSPC: 0
Wed Jun 3 11:07:03.414 filesystem: fsync time: 1362438
Wed Jun 3 11:07:03.414 filesystem: fsync count: 724
Wed Jun 3 11:07:03.414 filesystem: long fsync time: 0
Wed Jun 3 11:07:03.414 filesystem: long fsync count: 0
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a full fetch: 0
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a partial fetch: 0
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a full eviction: 0
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a partial eviction: 6
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a message injection: 0
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a message application: 0
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a flush: 0
Wed Jun 3 11:07:03.414 context: tree traversals blocked by a the cleaner thread: 1
Wed Jun 3 11:07:03.414 context: tree traversals blocked by something uninstrumented: 2416
Wed Jun 3 11:07:03.414 context: promotion blocked by a full fetch (should never happen): 0
Wed Jun 3 11:07:03.414 context: promotion blocked by a partial fetch (should never happen): 0
Wed Jun 3 11:07:03.414 context: promotion blocked by a full eviction (should never happen): 0
Wed Jun 3 11:07:03.414 context: promotion blocked by a partial eviction (should never happen): 0
Wed Jun 3 11:07:03.414 context: promotion blocked by a message injection: 0
Wed Jun 3 11:07:03.414 context: promotion blocked by a message application: 0
Wed Jun 3 11:07:03.414 context: promotion blocked by a flush: 0
Wed Jun 3 11:07:03.414 context: promotion blocked by the cleaner thread: 0
Wed Jun 3 11:07:03.414 context: promotion blocked by something uninstrumented: 0
Wed Jun 3 11:07:03.414 context: something uninstrumented blocked by something uninstrumented: 0
Wed Jun 3 11:07:03.414 Memory usage:

Wed Jun 3 11:07:03.421
Wed Jun 3 11:07:03.421 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.421 Crash reason:
Wed Jun 3 11:07:03.421
Wed Jun 3 11:07:03.421 Got signal: 6 (Aborted).
Wed Jun 3 11:07:03.421
Wed Jun 3 11:07:03.421 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.421 Process info:
Wed Jun 3 11:07:03.421
Wed Jun 3 11:07:03.424 OS: Linux Amazon Linux AMI release 2015.03 Kernel 3.14.33-26.47.amzn1.x86_64 x86_64
Wed Jun 3 11:07:03.424 NCPU: 2
Wed Jun 3 11:07:03.431 VIRT: 7107 MB
Wed Jun 3 11:07:03.431 RES: 7107 MB
Wed Jun 3 11:07:03.431 PHYS: 15302 MB
Wed Jun 3 11:07:03.431 RLIMIT_CORE: 0 (soft), unlimited (hard)
Wed Jun 3 11:07:03.431 RLIMIT_CPU: unlimited (soft), unlimited (hard)
Wed Jun 3 11:07:03.431 RLIMIT_DATA: unlimited (soft), unlimited (hard)
Wed Jun 3 11:07:03.431 RLIMIT_FSIZE: unlimited (soft), unlimited (hard)
Wed Jun 3 11:07:03.431 RLIMIT_NOFILE: 1024 (soft), 4096 (hard)
Wed Jun 3 11:07:03.431 RLIMIT_STACK: 8388608 (soft), unlimited (hard)
Wed Jun 3 11:07:03.431 RLIMIT_AS: unlimited (soft), unlimited (hard)
Wed Jun 3 11:07:03.431 _SC_OPEN_MAX: 1024
Wed Jun 3 11:07:03.431 _SC_PAGESIZE: 4096
Wed Jun 3 11:07:03.431 _SC_PHYS_PAGES: 3917503
Wed Jun 3 11:07:03.431 _SC_AVPHYS_PAGES: 39159
Wed Jun 3 11:07:03.431 _SC_NPROCESSORS_CONF: 2
Wed Jun 3 11:07:03.431 _SC_NPROCESSORS_ONLN: 2
Wed Jun 3 11:07:03.431
Wed Jun 3 11:07:03.431 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.431 Parsed server options:
Wed Jun 3 11:07:03.431
Wed Jun 3 11:07:03.434 cacheSize: 5368709120
Wed Jun 3 11:07:03.435 command: [ "run" ]
Wed Jun 3 11:07:03.435 config: "/etc/tokumx.conf"
Wed Jun 3 11:07:03.435 dbpath: "/var/lib/tokumx-fresh"
Wed Jun 3 11:07:03.435 fork: "true"
Wed Jun 3 11:07:03.435 logappend: "true"
Wed Jun 3 11:07:03.435 logpath: "/var/log/tokumx/tokumx.log"
Wed Jun 3 11:07:03.435 pidfilepath: "/var/run/tokumx/tokumx.pid"
Wed Jun 3 11:07:03.435 pluginsDir: "/usr/lib64/tokumx/plugins"
Wed Jun 3 11:07:03.435 quiet: true
Wed Jun 3 11:07:03.435 verbose: "true"
Wed Jun 3 11:07:03.435
Wed Jun 3 11:07:03.435 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.435 Filesystem information:
Wed Jun 3 11:07:03.435
Wed Jun 3 11:07:03.437 Information for dbpath "/var/lib/tokumx-fresh":
Wed Jun 3 11:07:03.437
Wed Jun 3 11:07:03.437 type magic: 0x0000EF53
Wed Jun 3 11:07:03.437 type: ext2/3/4
Wed Jun 3 11:07:03.437 bsize: 4096
Wed Jun 3 11:07:03.437 blocks: 64474460
Wed Jun 3 11:07:03.437 bfree: 32729415
Wed Jun 3 11:07:03.437 bavail: 32704353
Wed Jun 3 11:07:03.437
Wed Jun 3 11:07:03.437 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.437 Current operations in progress:
Wed Jun 3 11:07:03.437
Wed Jun 3 11:07:03.446 { opid: 6517, active: false, op: "query", ns: "", query: { createdOn: { $lte: new Date(1433354115108) } }, client: "127.0.0.1:37381", desc: "conn50", threadId: "0x7fb249bfb700", connectionId: 50, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.446 { opid: 6516, active: false, op: "query", ns: "", query: { processState: "SUCCESS" }, client: "127.0.0.1:37383", desc: "conn51", threadId: "0x7fb249afa700", connectionId: 51, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.446 { opid: 5692, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:37194", desc: "conn43", threadId: "0x7fb253fff700", connectionId: 43, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 1260, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.446 { opid: 2795, active: false, op: "query", ns: "vroozi.shopper_lists", query: { userId: "2", unitId: "2", listType: { $nin: [ "LIST_SHOPPING_CART", "LIST_FAVORITES", "LIST_COMPARE" ] } }, client: "127.0.0.1:36818", desc: "conn34", threadId: "0x7fb38a2fe700", connectionId: 34, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 164152, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.446 { opid: 2782, active: false, op: "query", ns: "vroozi.announcements", query: { query: { unitId: 2, filterUsers: { $nin: [ "2" ] }, mailingList: { $in: [ "144" ] } }, orderby: { date: -1 } }, client: "127.0.0.1:36538", desc: "conn26", threadId: "0x7fb393dfc700", connectionId: 26, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 1152, w: 0 }, timeAcquiringMicros: { r: 4, w: 0 } } }
Wed Jun 3 11:07:03.446 { opid: 7128, active: false, op: "query", ns: "content.process", query: { processState: "SUCCESS" }, client: "127.0.0.1:36398", desc: "conn12", threadId: "0x7fb3b1bfc700", connectionId: 12, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 280, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.446 { opid: 5585, active: false, op: "query", ns: "vroozi.profile_group", query: { unitId: "2", token: "null", active: true }, client: "127.0.0.1:37155", desc: "conn42", threadId: "0x7fb3849f9700", connectionId: 42, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 2051, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.446 { opid: 5481, active: false, op: "query", ns: "vroozi.user", query: { userId: "2", deleted: false }, client: "127.0.0.1:36429", desc: "conn15", threadId: "0x7fb3b0ffb700", connectionId: 15, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 10576, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.446 { opid: 1506, active: false, op: "getmore", ns: "vroozi.user", query: {}, client: "127.0.0.1:36462", desc: "conn22", threadId: "0x7fb395afd700", connectionId: 22, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 8323, w: 0 }, timeAcquiringMicros: { r: 2, w: 0 } } }
Wed Jun 3 11:07:03.447 { opid: 2818, active: false, op: "query", ns: "vroozi.supplier", query: { _id: { $in: [ "98", "763", "773", "79", "127", "132", "114", "128", "133", "115", "751", "113", "139", "124", "129", "2", "0", "885", "131", "141" ] }, active: true, includeSupplierCard: true }, client: "127.0.0.1:36811", desc: "conn29", threadId: "0x7fb38d9fc700", connectionId: 29, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 905, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.447 { opid: 2386, active: false, op: "killcursors", ns: "", query: {}, client: "127.0.0.1:36459", desc: "conn20", threadId: "0x7fb3af1fc700", connectionId: 20, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.447 { opid: 5573, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:36560", desc: "conn27", threadId: "0x7fb38dbfe700", connectionId: 27, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 431, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.447 { opid: 2794, active: false, op: "query", ns: "vroozi.saved_searches", query: { userId: "2", unitId: "2" }, client: "127.0.0.1:36819", desc: "conn35", threadId: "0x7fb38a1fd700", connectionId: 35, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 1324, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.447 { opid: 6062, active: false, op: "query", ns: "", query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 }, client: "127.0.0.1:37316", desc: "conn46", threadId: "0x7fb249fff700", connectionId: 46, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.448 { opid: 161, active: false, op: "query", ns: "vroozi.company_settings", query: { userName: null, password: null }, client: "127.0.0.1:36390", desc: "conn7", threadId: "0x7fb3b52f2700", connectionId: 7, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 1338, w: 0 }, timeAcquiringMicros: { r: 2, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 7125, active: false, op: "getmore", ns: "vroozi.process", query: {}, client: "127.0.0.1:36395", desc: "conn9", threadId: "0x7fb3b3bfe700", connectionId: 9, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 1414, w: 0 }, timeAcquiringMicros: { r: 3, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 5744, active: false, op: "query", ns: "vroozi.seq_collection", query: { name: "seq_document_flow_2" }, client: "127.0.0.1:37075", desc: "conn39", threadId: "0x7fb384cfc700", connectionId: 39, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 109, w: 0 }, timeAcquiringMicros: { r: 3, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 5732, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:37245", desc: "conn44", threadId: "0x7fb253efe700", connectionId: 44, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 430, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 6968, active: false, op: "query", ns: "", query: { createdOn: { $lte: new Date(1433354415212) } }, client: "127.0.0.1:37453", desc: "conn52", threadId: "0x7fb2499f9700", connectionId: 52, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.448 { opid: 2783, active: false, op: "query", ns: "vroozi.profile", query: { unitId: "2", active: true, isSupplierAssociated: false }, client: "127.0.0.1:36813", desc: "conn31", threadId: "0x7fb38c6fe700", connectionId: 31, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 2296, w: 0 }, timeAcquiringMicros: { r: 4, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 5568, active: false, op: "query", ns: "vroozi.user", query: { userId: "2", deleted: false }, client: "127.0.0.1:36526", desc: "conn23", threadId: "0x7fb3959fc700", connectionId: 23, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 15654, w: 0 }, timeAcquiringMicros: { r: 8, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 6063, active: false, op: "query", ns: "", query: { createdOn: { $lte: new Date(1433353795904) } }, client: "127.0.0.1:37319", desc: "conn49", threadId: "0x7fb249cfc700", connectionId: 49, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.448 { opid: 1101, active: false, op: "query", ns: "vroozi.user", query: { findandmodify: "user", query: { username: "shaz.khan+tester@vroozi.com", unitId: "2", active: true, deleted: false }, update: { $set: { userStatus: "Active" } } }, client: "127.0.0.1:36427", desc: "conn14", threadId: "0x7fb3b19fa700", connectionId: 14, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 219, w: 0 }, timeAcquiringMicros: { r: 2, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 5425, active: false, op: "query", ns: "vroozi.user", query: { findandmodify: "user", query: { username: "shaz.khan+tester@vroozi.com", unitId: "2", active: true, deleted: false }, update: { $set: { userStatus: "Active" } } }, client: "127.0.0.1:37005", desc: "conn36", threadId: "0x7fb384fff700", connectionId: 36, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 225, w: 0 }, timeAcquiringMicros: { r: 3, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 1266, active: false, op: "query", ns: "vroozi.user_session_data", query: { _id: ObjectId('556f3979e4b0616b50c825a5') }, client: "127.0.0.1:36460", desc: "conn21", threadId: "0x7fb395bfe700", connectionId: 21, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 76, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 5572, active: false, op: "query", ns: "vroozi.shopping_items", query: { query: { listId: "216", checkedOut: { $ne: true } }, orderby: { bundleNumber: 1, supplierId: -1 } }, client: "127.0.0.1:36800", desc: "conn28", threadId: "0x7fb38dafd700", connectionId: 28, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 391, w: 0 }, timeAcquiringMicros: { r: 3, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 5646, active: false, op: "query", ns: "", query: { expireAfterSeconds: { $exists: true } }, client: "0.0.0.0:0", desc: "TTLMonitor", threadId: "0x7fb3b17fc700", rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.448 { opid: 5733, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:36458", desc: "conn19", threadId: "0x7fb3af2fd700", connectionId: 19, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 351, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 7127, active: false, op: "getmore", ns: "vroozi.messages", query: {}, client: "127.0.0.1:36384", desc: "conn6", threadId: "0x7fb3b53f3700", connectionId: 6, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 329709, w: 0 }, timeAcquiringMicros: { r: 3, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 266, active: false, op: "query", ns: "content.iso_currencies", query: { count: "iso_currencies", query: {} }, client: "127.0.0.1:36397", desc: "conn11", threadId: "0x7fb3b39fc700", connectionId: 11, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 216, w: 0 }, timeAcquiringMicros: { r: 2, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 1690, active: false, op: "query", ns: "vroozi.profile", query: { unitId: "2", active: true, isSupplierAssociated: false }, client: "127.0.0.1:36536", desc: "conn25", threadId: "0x7fb393efd700", connectionId: 25, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 4434, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.448 { opid: 2824, active: false, op: "query", ns: "", query: { getlasterror: 1, w: 1, wtimeout: 0, fsync: true }, client: "127.0.0.1:36817", desc: "conn33", threadId: "0x7fb38a3ff700", connectionId: 33, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 5577, active: false, op: "query", ns: "vroozi.shopper_lists", query: { userId: "2", unitId: "2", listType: { $nin: [ "LIST_SHOPPING_CART", "LIST_FAVORITES", "LIST_COMPARE" ] } }, client: "127.0.0.1:37133", desc: "conn41", threadId: "0x7fb384afa700", connectionId: 41, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 35786, w: 0 }, timeAcquiringMicros: { r: 4, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 0, active: false, op: "none", ns: "", query: {}, desc: "clientcursormon", threadId: "0x7fb3b2bfe700", rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 119, active: false, op: "query", ns: "vroozi.company_settings", query: { userName: null, password: null }, client: "127.0.0.1:36383", desc: "conn5", threadId: "0x7fb3c25d6700", connectionId: 5, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 1500, w: 0 }, timeAcquiringMicros: { r: 23, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 6061, active: false, op: "query", ns: "", query: { processState: "SUCCESS" }, client: "127.0.0.1:37318", desc: "conn48", threadId: "0x7fb249dfd700", connectionId: 48, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 6969, active: false, op: "query", ns: "", query: { processState: "SUCCESS" }, client: "127.0.0.1:37454", desc: "conn53", threadId: "0x7fb20f7ff700", connectionId: 53, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 7134, active: false, op: "getmore", ns: "vroozi.process", query: {}, client: "127.0.0.1:36396", desc: "conn10", threadId: "0x7fb3b3afd700", connectionId: 10, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 1389, w: 0 }, timeAcquiringMicros: { r: 2, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 5569, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:37108", desc: "conn40", threadId: "0x7fb384bfb700", connectionId: 40, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 481, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 2790, active: false, op: "query", ns: "", query: { getlasterror: 1, w: 1, wtimeout: 0 }, client: "127.0.0.1:36814", desc: "conn32", threadId: "0x7fb38c5fd700", connectionId: 32, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 5485, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:36448", desc: "conn18", threadId: "0x7fb3af3fe700", connectionId: 18, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 365, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 1458, active: false, op: "query", ns: "", query: { getlasterror: 1, w: 1, wtimeout: 0 }, client: "127.0.0.1:36530", desc: "conn24", threadId: "0x7fb393ffe700", connectionId: 24, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 0, active: false, op: "none", ns: "", query: {}, desc: "snapshotthread", threadId: "0x7fb3b33ff700", rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 6060, active: false, op: "query", ns: "", query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 }, client: "127.0.0.1:36380", desc: "conn4", threadId: "0x7fb3c26d7700", connectionId: 4, rootTxnid: 1030250306, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 1114, active: false, op: "query", ns: "vroozi.user_session_data", query: { _id: ObjectId('556f3979e4b0616b50c825a5') }, client: "127.0.0.1:36432", desc: "conn17", threadId: "0x7fb3b0df9700", connectionId: 17, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 97, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 7131, active: false, op: "query", ns: "", query: { buildinfo: 1 }, client: "127.0.0.1:36379", desc: "conn3", threadId: "0x7fb3c9d6f700", connectionId: 3, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 5734, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:37049", desc: "conn38", threadId: "0x7fb384dfd700", connectionId: 38, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 356, w: 0 }, timeAcquiringMicros: { r: 6, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 5582, active: true, secs_running: 1008, op: "insert", ns: "catalog.system.indexes", insert: {}, client: "127.0.0.1:36394", desc: "conn8", threadId: "0x7fb3b51f1700", connectionId: 8, rootTxnid: 1030250420, locks: { ^: "w", ^catalog: "W" }, context: "insert (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/instance.cpp:997)", waitingForLock: false, msg: "Foreground index build progress (collect phase) for catalog.catalog_item, key { newItemExtQuoteId: 1 }: 110882000/112038199 98% (estimated documents)
", lockStats: { timeLockedMicros: { r: 101, w: 0 }, timeAcquiringMicros: { r: 9, w: 3 } } }
Wed Jun 3 11:07:03.449 { opid: 2817, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:36812", desc: "conn30", threadId: "0x7fb38c7ff700", connectionId: 30, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 418, w: 0 }, timeAcquiringMicros: { r: 8, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 1256, active: false, op: "query", ns: "vroozi.user", query: { findandmodify: "user", query: { username: "shaz.khan+tester@vroozi.com", unitId: "2", active: true, deleted: false }, update: { $set: { userStatus: "Active" } } }, client: "127.0.0.1:36430", desc: "conn16", threadId: "0x7fb3b0efa700", connectionId: 16, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 231, w: 0 }, timeAcquiringMicros: { r: 2, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 7132, active: false, op: "query", ns: "", query: { buildinfo: 1 }, client: "127.0.0.1:36376", desc: "conn2", threadId: "0x7fb3cbaa8700", connectionId: 2, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 5735, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:37007", desc: "conn37", threadId: "0x7fb384efe700", connectionId: 37, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 355, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 6064, active: false, op: "query", ns: "", query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 }, client: "127.0.0.1:37317", desc: "conn47", threadId: "0x7fb249efe700", connectionId: 47, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 5486, active: false, op: "query", ns: "vroozi.company_settings", query: { unitId: "2" }, client: "127.0.0.1:36419", desc: "conn13", threadId: "0x7fb3b1afb700", connectionId: 13, rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 386, w: 0 }, timeAcquiringMicros: { r: 7, w: 0 } } }
Wed Jun 3 11:07:03.449 { opid: 6065, active: false, op: "query", ns: "", query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 }, client: "127.0.0.1:37315", desc: "conn45", threadId: "0x7fb253dfd700", connectionId: 45, rootTxnid: 0, locks: { ^catalog: "R" }, context: "query (/data/package-rpm-el6/build/BUILD/tokumx-2.0.1/src/mongo/db/ops/query.cpp:1003)", waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449 { opid: 0, active: false, op: "insert", ns: "local.startup_log", insert: {}, client: "0.0.0.0:0", desc: "initandlisten", threadId: "0x7fb3cbab1840", rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: { r: 85, w: 5368 }, timeAcquiringMicros: { r: 4, w: 1 } } }
Wed Jun 3 11:07:03.449 { opid: 0, active: false, op: "none", ns: "", query: {}, desc: "websvr", threadId: "0x7fb3afbff700", rootTxnid: 0, waitingForLock: false, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } }
Wed Jun 3 11:07:03.449
Wed Jun 3 11:07:03.449 --------------------------------------------------------------------------------
Wed Jun 3 11:07:03.449 OpDebug info:
Wed Jun 3 11:07:03.450
Wed Jun 3 11:07:03.450 query catalog.item_tracker query: { createdOn: { $lte: new Date(1433354115108) } } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 query catalog.process query: { processState: "SUCCESS" } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:1260 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:164152 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:1152 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:280 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:2051 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:10576 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:8323 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:905 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:431 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:1324 0ms
Wed Jun 3 11:07:03.450 query catalog.catalog_item query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:1338 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:1414 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:109 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:430 0ms
Wed Jun 3 11:07:03.450 query catalog.item_tracker query: { createdOn: { $lte: new Date(1433354415212) } } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:2296 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:15654 0ms
Wed Jun 3 11:07:03.450 query catalog.item_tracker query: { createdOn: { $lte: new Date(1433353795904) } } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:219 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:225 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:76 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:391 0ms
Wed Jun 3 11:07:03.450 query catalog.system.indexes query: { expireAfterSeconds: { $exists: true } } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:351 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:329709 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:216 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:4434 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:35786 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:1500 0ms
Wed Jun 3 11:07:03.450 query catalog.process query: { processState: "SUCCESS" } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 query catalog.process query: { processState: "SUCCESS" } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:1389 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:481 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:365 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 query catalog.catalog_item query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:97 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:356 0ms
Wed Jun 3 11:07:03.450 insert catalog.system.indexes keyUpdates:0 locks(micros) r:101 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:418 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:231 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.450 none keyUpdates:0 locks(micros) r:355 0ms
Wed Jun 3 11:07:03.451 query catalog.catalog_item query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.451 none keyUpdates:0 locks(micros) r:386 0ms
Wed Jun 3 11:07:03.451 query catalog.catalog_item query: { _id: { $in: [ ObjectId('5562ff58e4b067544fb8ada2') ] }, deleted: 0 } ntoreturn:0 keyUpdates:0 0ms
Wed Jun 3 11:07:03.451 none keyUpdates:0 locks(micros) r:85 w:5368 0ms
Wed Jun 3 11:07:03.451 none keyUpdates:0 0ms
Wed Jun 3 11:07:03.451
Wed Jun 3 11:26:36.789 nssize is a deprecated parameter
forked process: 7514
all output going to: /var/log/tokumx/tokumx.log

[adeelahmadch]

Found the same issue here:
#1219

[adeelahmadch]

i tested it further and its a bug in tokumx. now i use Server with 120GB RAM and 500GB HDD. i didn't specify cache size which means that line is comment in tokumx.conf. i tried to build the index and it crashed.

what i found is:

1. if i try to build index in foreground on large collection, no matter what OS, what size of RAM and ulimits are set , tokumx crashes.
   db.catalog_item.createIndex( { newItemExtQuoteId : 1 } , { sparse: true })
2. if we build index in background on large collection(95190736 items) it worked fine and consume less resources. in my case i was able to that on a server with 15GB RAM and 5GB cache size assigned to tokumx.
   db.catalog_item.createIndex( { newItemExtQuoteId : 1 } , { sparse: true, background: true })

i am expecting more from tokumx, crashing is not an option, it should throw some kind of error instead of crashing.

[esmet]

What does the servers log say?

Sent from my iPhone

On Jun 4, 2015, at 4:41 PM, Adeel Ahmad notifications@github.com wrote:

i tested it further and its a bug in tokumx. now i use Server with 120GB RAM and 500GB HDD. i didn't specify cache size which means that line is comment in tokumx.conf. i tried to build the index and it crashed.

what i found is:

if i try to build index in foreground on large collection, no matter what OS, what size of RAM and ulimits are set , tokumx crashes.
db.catalog_item.createIndex( { newItemExtQuoteId : 1 } , { sparse: true })

if we build index in background on large collection(95190736 items) it worked fine and consume less resources. in my case i was able to that on a server with 15GB RAM and 5GB cache size assigned to tokumx.
db.catalog_item.createIndex( { newItemExtQuoteId : 1 } , { sparse: true, background: true })

i am expecting more from tokumx, crashing is not an option, it should throw some kind of error instead of crashing.

—
Reply to this email directly or view it on GitHub.

[sdeusch]

Server log throughout crash is above.

[adeelahmadch]

Server logs are attached above. TokuMx 2.0.1 is not stable with indexing.

now i tried to build the index in background which works previously when i did not perform any other operation. This time it crashed again when i am building the same index. it was on 19% and i performed another operation on some other DB and it crashed.

[esmet]

Looks like the source data may be bad, as the previous issue you linked showed "Checksum failure when reading data from disk"

Surviving a corrupted data read is not really that important, since you cannot continue if you can't trust the data on disk. This replica set member needs to be wiped and resyncd.

[adeelahmadch]

yes, that's was some other user issue, in my case data it not corrupted.

i was able to build my indexes one by one using background: true options. it appears to me that tokumx doesn't handle index in foreground. if you try to build multiple large index in foreground it crash.