[SERVER-3478] using sort and geo query within the map/reduce call mongoD drops Created: 26/Jul/11  Updated: 12/Jul/16  Resolved: 05/Aug/11

Status: Closed
Project: Core Server
Component/s: Geo, Index Maintenance
Affects Version/s: 1.9.0
Fix Version/s: 1.9.2

Type: Bug Priority: Major - P3
Reporter: Veniamin Assignee: Greg Studer
Resolution: Done Votes: 1
Labels: commands, crash, mapreduce,, query
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Oracle Linux Server release 6.1
Kernel \r on an \m


Attachments: File benchmark02.rb    
Operating System: Linux
Participants:

 Description   

db.users.mapReduce(m, r, { out : 'users_mr', sort : {_id:1}, query : {'location': { $within:

{ $centerSphere: [[ 10, 20 ], 1 ]}

}} });

Tue Jul 26 18:17:41 [initandlisten] db version v1.9.0, pdfile version 4.5
Tue Jul 26 18:17:41 [initandlisten] git version: 434d8b47e569578d932e3caedd3bb16e8c0836a3
Tue Jul 26 18:17:41 [initandlisten] build info: Linux bs-linux64.10gen.cc 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_41
Tue Jul 26 18:17:41 [initandlisten] waiting for connections on port 27017
Tue Jul 26 18:17:41 [websvr] web admin interface listening on port 28017
Tue Jul 26 18:17:42 [initandlisten] connection accepted from 127.0.0.1:35696 #1
Tue Jul 26 18:18:32 [conn2] CMD: drop teamo.tmp.mr.users_users_mr_3
Tue Jul 26 18:18:32 [conn2] CMD: drop teamo.tmp.mr.users_users_mr_3_inc
Tue Jul 26 18:18:32 [conn2] building new index on

{ 0: 1 }

for teamo.tmp.mr.users_users_mr_3_inc
Tue Jul 26 18:18:32 [conn2] done for 0 records 0.016 secs
Tue Jul 26 18:18:32 [conn2] insert teamo.system.indexes 16ms
Tue Jul 26 18:18:32 [conn2] profile: warning ns teamo.system.profile does not exist
Tue Jul 26 18:18:33 [conn2] warning: best guess query plan requested, but scan and order are required for all plans query: { location.geo: { $within:

{ $centerSphere: [ [ 37.0, 0.0 ], 1.0 ] }

} } order:

{ _id: 1.0 }

choices:

{ location.geo: "2d" }

Tue Jul 26 18:18:33 Got signal: 6 (Aborted).

Tue Jul 26 18:18:33 Backtrace:
0x92d809 0x2ae508a31ac0 0x2ae508a31a45 0x2ae508a33225 0x2ae508a2a9d5 0x6c6d5e 0x878e5f 0x83656c 0x837525 0x678418 0x67a9bc 0x79c495 0x7a3493 0x93c91f 0x5e46e5 0x946800 0x2ae5080487e1 0x2ae508ae58ed
/usr/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x92d809]
/lib64/libc.so.6(+0x32ac0) [0x2ae508a31ac0]
/lib64/libc.so.6(gsignal+0x35) [0x2ae508a31a45]
/lib64/libc.so.6(abort+0x175) [0x2ae508a33225]
/lib64/libc.so.6(__assert_fail+0xf5) [0x2ae508a2a9d5]
/usr/bin/mongod(_ZN5mongo12ClientCursorC1EiRKN5boost10shared_ptrINS_6CursorEEERKSsNS_7BSONObjE+0x70e) [0x6c6d5e]
/usr/bin/mongod(_ZN5mongo2mr16MapReduceCommand3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0x47f) [0x878e5f]
/usr/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x7fc) [0x83656c]
/usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x2d5) [0x837525]
/usr/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x38) [0x678418]
/usr/bin/mongod(ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1+0xe9c) [0x67a9bc]
/usr/bin/mongod() [0x79c495]
/usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xde3) [0x7a3493]
/usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x7f) [0x93c91f]
/usr/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x3e5) [0x5e46e5]
/usr/bin/mongod(thread_proxy+0x80) [0x946800]
/lib64/libpthread.so.0(+0x77e1) [0x2ae5080487e1]
/lib64/libc.so.6(clone+0x6d) [0x2ae508ae58ed]

Tue Jul 26 18:18:33 dbexit:
Tue Jul 26 18:18:33 [conn2] shutdown: going to close listening sockets...
Tue Jul 26 18:18:33 [conn2] closing listening socket: 5
Tue Jul 26 18:18:33 [conn2] closing listening socket: 6
Tue Jul 26 18:18:33 [conn2] closing listening socket: 7
Tue Jul 26 18:18:33 [conn2] removing socket file: /tmp/mongodb-27017.sock
Tue Jul 26 18:18:33 [conn2] shutdown: going to flush diaglog...
Tue Jul 26 18:18:33 [conn2] shutdown: going to close sockets...
Tue Jul 26 18:18:33 [conn2] shutdown: waiting for fs preallocator...
Tue Jul 26 18:18:33 [conn2] shutdown: closing all files...
Tue Jul 26 18:18:33 [conn2] closeAllFiles() finished
Tue Jul 26 18:18:33 [conn2] shutdown: removing fs lock...
Tue Jul 26 18:18:33 dbexit: really exiting now
Tue Jul 26 18:18:33 Got signal: 6 (Aborted).

Tue Jul 26 18:18:33 Backtrace:
0x92d809 0x2ae508a31ac0 0x2ae508a31a45 0x2ae508a33225 0x2ae508a2a9d5 0x6c4638 0x2ae508a35072 0x79a8e8 0x92d966 0x2ae508a31ac0 0x2ae508a31a45 0x2ae508a33225 0x2ae508a2a9d5 0x6c6d5e 0x878e5f 0x83656c 0x837525 0x678418 0x67a9bc 0x79c495
/usr/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x92d809]
/lib64/libc.so.6(+0x32ac0) [0x2ae508a31ac0]
/lib64/libc.so.6(gsignal+0x35) [0x2ae508a31a45]
/lib64/libc.so.6(abort+0x175) [0x2ae508a33225]
/lib64/libc.so.6(__assert_fail+0xf5) [0x2ae508a2a9d5]
/usr/bin/mongod() [0x6c4638]
/lib64/libc.so.6(exit+0xe2) [0x2ae508a35072]
/usr/bin/mongod(_ZN5mongo6dbexitENS_8ExitCodeEPKcb+0x198) [0x79a8e8]
/usr/bin/mongod(_ZN5mongo10abruptQuitEi+0x4f6) [0x92d966]
/lib64/libc.so.6(+0x32ac0) [0x2ae508a31ac0]
/lib64/libc.so.6(gsignal+0x35) [0x2ae508a31a45]
/lib64/libc.so.6(abort+0x175) [0x2ae508a33225]
/lib64/libc.so.6(__assert_fail+0xf5) [0x2ae508a2a9d5]
/usr/bin/mongod(_ZN5mongo12ClientCursorC1EiRKN5boost10shared_ptrINS_6CursorEEERKSsNS_7BSONObjE+0x70e) [0x6c6d5e]
/usr/bin/mongod(_ZN5mongo2mr16MapReduceCommand3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0x47f) [0x878e5f]
/usr/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x7fc) [0x83656c]
/usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x2d5) [0x837525]
/usr/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x38) [0x678418]
/usr/bin/mongod(ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1+0xe9c) [0x67a9bc]
/usr/bin/mongod() [0x79c495]

Tue Jul 26 18:18:33 dbexit: ; exiting immediately
Tue Jul 26 18:18:33 ERROR: Client::~Client _context should be null but is not; client:conn



 Comments   
Comment by auto [ 04/Dec/11 ]

Author:

{u'login': u'astaple', u'name': u'Aaron', u'email': u'aaron@10gen.com'}

Message: SERVER-3478 minor cleanup and comments for cached plan handling
Branch: master
https://github.com/mongodb/mongo/commit/d8bb81b35289fd64c7db538cabc271d28b139e04

Comment by auto [ 04/Dec/11 ]

Author:

{u'login': u'astaple', u'name': u'Aaron', u'email': u'aaron@10gen.com'}

Message: SERVER-3478 clarify meaning of attribute representing cached plans and set it correctly for simple _id and geo queries
Branch: master
https://github.com/mongodb/mongo/commit/e86d2a2ce76204048fb71cbfe79169620d99917b

Comment by Greg Studer [ 05/Aug/11 ]

Should be fixed, feel free to reopen if you get further mongod drops

Comment by auto [ 05/Aug/11 ]

Author:

{u'login': u'gregstuder', u'name': u'gregs', u'email': u'greg@10gen.com'}

Message: handle m/r errors via assertion exceptions to keep consistent error interface SERVER-3478
Branch: master
https://github.com/mongodb/mongo/commit/a19bd10c50c12a03fc894c8b3d19bc75a6826121

Comment by auto [ 05/Aug/11 ]

Author:

{u'login': u'gregstuder', u'name': u'gregs', u'email': u'greg@10gen.com'}

Message: don't throw error with unfulfillable query in mr SERVER-3478
Branch: master
https://github.com/mongodb/mongo/commit/b96bd28ad5171a4246aca4417ef7e481d0116d05

Comment by Greg Studer [ 05/Aug/11 ]

Actually have a fix for the above, will try to push it soon. Mostly just running it through the regression tests now.

Comment by Greg Studer [ 03/Aug/11 ]

Thanks, fix for the crash should be simple, but again the in-mem sort will probably need to be deferred until after 2.0.

Comment by Yury [ 03/Aug/11 ]

Wed Aug 3 13:16:32 [initandlisten] MongoDB starting : pid=13094 port=27018 dbpath=/var/lib/mongodb/r01 32-bit host=ubuntu

    • NOTE: This is a development version (1.9.1) of MongoDB.
    • Not recommended for production.

Wed Aug 3 13:16:32 [initandlisten] db version v1.9.1, pdfile version 4.5
Wed Aug 3 13:16:32 [initandlisten] git version: dfcdcf1853aeccad42741e8fe858dd5c3056f888
Wed Aug 3 13:16:32 [initandlisten] build info: Linux ubuntu 2.6.38-8-generic-pae #42-Ubuntu SMP Mon Apr 11 05:17:09 UTC 2011 i686 BOOST_LIB_VERSION=1_42
Wed Aug 3 13:16:32 [initandlisten] options:

{ dbpath: "/var/lib/mongodb/r01", logappend: true, logpath: "/var/log/mongodb/r01.log", port: 27018, replSet: "testlocaldev", shardsvr: true }

Wed Aug 3 13:16:32 [initandlisten] waiting for connections on port 27018
Wed Aug 3 13:16:32 [websvr] web admin interface listening on port 28018
Wed Aug 3 13:16:32 [initandlisten] connection accepted from 127.0.0.1:35431 #1
Wed Aug 3 13:16:32 [initandlisten] connection accepted from 10.0.2.2:52535 #2
Wed Aug 3 13:16:32 [rsStart] replSet STARTUP2
Wed Aug 3 13:16:32 [conn4] end connection 10.0.2.2:52535
Wed Aug 3 13:16:32 [rsSync] replSet SECONDARY
Wed Aug 3 13:16:32 [rsMgr] replSet total number of votes is even - add arbiter or give one member an extra vote
Wed Aug 3 13:16:32 [rsMgr] replSet can't see a majority, will not try to elect self
Wed Aug 3 13:16:32 [initandlisten] connection accepted from 10.0.2.2:52537 #3
Wed Aug 3 13:16:32 [rsHealthPoll] replSet info member 172.19.37.190:27019 is up
Wed Aug 3 13:16:32 [rsHealthPoll] replSet member 172.19.37.190:27019 is now in state SECONDARY
Wed Aug 3 13:16:32 [rsMgr] not electing self, 172.19.37.190:27019 would veto
Wed Aug 3 13:16:37 [initandlisten] connection accepted from 127.0.0.1:35437 #4
Wed Aug 3 13:16:38 [rsMgr] replSet info electSelf 0
Wed Aug 3 13:16:38 [rsMgr] replSet PRIMARY
Wed Aug 3 13:16:39 [initandlisten] connection accepted from 10.0.2.2:58375 #5
Wed Aug 3 13:16:39 [initandlisten] connection accepted from 10.0.2.2:58376 #6
Wed Aug 3 13:16:41 [initandlisten] connection accepted from 10.0.2.2:52580 #7
Wed Aug 3 13:17:17 [conn12] command test.$cmd command: { count: "users", query: { _id:

{ $lte: 100538, $gt: 538, $nin: [ 2999, 662787, 692593 ] }

, sex: 1, looking_for:

{ $in: [ 2, 3 ] }

, premium_till:

{ $gte: new Date(1312377437647) }

, overmatched_in:

{ $ne: [ "nobody", "old_users" ] }

} } ntoreturn:1 reslen:48 255ms
Wed Aug 3 13:17:17 [conn12] CMD: drop test.tmp.mr.users_0_inc
Wed Aug 3 13:17:17 [conn12] build index test.tmp.mr.users_0_inc

{ 0: 1 }

Wed Aug 3 13:17:17 [conn12] build index done 0 records 0 secs
Wed Aug 3 13:17:17 [conn12] CMD: drop test.tmp.mr.users_0
Wed Aug 3 13:17:17 [conn12] build index test.tmp.mr.users_0

{ _id: 1 }

Wed Aug 3 13:17:17 [conn12] build index done 0 records 0 secs
mongod: /usr/include/boost/smart_ptr/shared_ptr.hpp:418: T* boost::shared_ptr< <template-parameter-1-1> >::operator->() const [with T = mongo::Cursor]: Assertion `px != 0' failed.
Wed Aug 3 13:17:17 Got signal: 6 (Aborted).

Wed Aug 3 13:17:17 Backtrace:
0x8534ecd 0x8529f9d 0xb76f0400 0xb76f0424 0xb723ae71 0xb723e34e 0xb7233888 0x82fe85e 0x84a1cd7 0x8463a0e 0x846409c 0x8440569 0x844298a 0x83c194e 0x8536343 0x8229925 0xb7376e99 0xb72e073e
/root/mongo/mongod(_ZN5mongo15printStackTraceERSo+0x2d) [0x8534ecd]
/root/mongo/mongod(_ZN5mongo10abruptQuitEi+0x3ed) [0x8529f9d]
[0xb76f0400]
[0xb76f0424]
/lib/i386-linux-gnu/libc.so.6(gsignal+0x51) [0xb723ae71]
/lib/i386-linux-gnu/libc.so.6(abort+0x17e) [0xb723e34e]
/lib/i386-linux-gnu/libc.so.6(__assert_fail+0xf8) [0xb7233888]
/root/mongo/mongod(_ZN5mongo12ClientCursorC2EiRKN5boost10shared_ptrINS_6CursorEEERKSsNS_7BSONObjE+0x7de) [0x82fe85e]
/root/mongo/mongod(_ZN5mongo2mr16MapReduceCommand3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0x3a7) [0x84a1cd7]
/root/mongo/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x8de) [0x8463a0e]
/root/mongo/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x29c) [0x846409c]
/root/mongo/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x49) [0x8440569]
/root/mongo/mongod(ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1+0x103a) [0x844298a]
/root/mongo/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xebe) [0x83c194e]
/root/mongo/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x83) [0x8536343]
/root/mongo/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x2b5) [0x8229925]
/lib/i386-linux-gnu/libpthread.so.0(+0x5e99) [0xb7376e99]
/lib/i386-linux-gnu/libc.so.6(clone+0x5e) [0xb72e073e]

Wed Aug 3 13:17:17 dbexit:
Wed Aug 3 13:17:17 [conn12] shutdown: going to close listening sockets...
Wed Aug 3 13:17:17 [conn12] closing listening socket: 5
Wed Aug 3 13:17:17 [conn12] closing listening socket: 6
Wed Aug 3 13:17:17 [conn12] closing listening socket: 7
Wed Aug 3 13:17:17 [conn12] removing socket file: /tmp/mongodb-27018.sock
Wed Aug 3 13:17:17 [conn12] shutdown: going to flush diaglog...
Wed Aug 3 13:17:17 [conn12] shutdown: going to close sockets...
Wed Aug 3 13:17:17 [conn12] shutdown: waiting for fs preallocator...
Wed Aug 3 13:17:17 [conn12] shutdown: closing all files...
Wed Aug 3 13:17:17 [conn12] closeAllFiles() finished
Wed Aug 3 13:17:17 [conn12] shutdown: removing fs lock...
Wed Aug 3 13:17:17 dbexit: really exiting now
Logstream::get called in uninitialized state
Wed Aug 3 13:17:17 [conn2] end connection 127.0.0.1:35431
Logstream::get called in uninitialized state
Wed Aug 3 13:17:17 ERROR: Client::~Client _context should be null but is not; client:conn

Comment by Yury [ 03/Aug/11 ]

problem repeating, then m/r query uses compound index (1.9.0)

Comment by Yury [ 02/Aug/11 ]

Tue Aug 02 09:55:42 [initandlisten] MongoDB starting : pid=5848 port=27017 dbpath=/data/db/ 64-bit host=ws-tm-179

    • NOTE: This is a development version (1.9.1) of MongoDB.
    • Not recommended for production.

Tue Aug 02 09:55:42 [initandlisten] db version v1.9.1, pdfile version 4.5
Tue Aug 02 09:55:42 [initandlisten] git version: dfcdcf1853aeccad42741e8fe858dd5c3056f888
Tue Aug 02 09:55:42 [initandlisten] build info: windows (6, 1, 7600, 2, '') BOOST_LIB_VERSION=1_42
Tue Aug 02 09:55:42 [initandlisten] options:

{ logpath: "c://data/mongod.log" }

Tue Aug 02 09:55:42 [initandlisten] waiting for connections on port 27017
Tue Aug 02 09:55:42 [websvr] web admin interface listening on port 28017
Tue Aug 02 09:55:46 [initandlisten] connection accepted from 127.0.0.1:51076 #1
Tue Aug 02 09:56:02 [conn2] CMD: drop test.tmp.mr.test_0_inc
Tue Aug 02 09:56:02 [conn2] build index test.tmp.mr.test_0_inc

{ 0: 1 }

Tue Aug 02 09:56:02 [conn2] build index done 0 records 0.001 secs
Tue Aug 02 09:56:02 [conn2] CMD: drop test.tmp.mr.test_0
Tue Aug 02 09:56:02 [conn2] build index test.tmp.mr.test_0

{ _id: 1 }

Tue Aug 02 09:56:02 [conn2] build index done 0 records 0.001 secs
Tue Aug 02 09:56:02 [conn2] Count with ns: test.test and query: { location: { $within:

{ $centerSphere: [ [ 10.0, 20.0 ], 1.0 ] }

} } failed with exception: exception: 13462 Spherical distance would require wrapping, which isn't implemented yet
Tue Aug 02 09:56:02 unhandled windows exception
Tue Aug 02 09:56:02 ec=0xc00000fd

Comment by Greg Studer [ 01/Aug/11 ]

@yury - can you send the stack trace from win7 x64 if it occurs, or are there just incorrect results?

Root cause is that in-memory sorts (as would be required to sort by _id) are only really supported for find() queries - fixing this aside from a better warning message will require some mods to the way we do cursors.

Comment by Yury [ 27/Jul/11 ]

Same problem on 1.9.1 - win7 x64

Comment by Greg Studer [ 26/Jul/11 ]

Just to add on to what I mentioned above - can reproduce in 1.9.0, there's no crash in 1.9.1.

Comment by Eliot Horowitz (Inactive) [ 26/Jul/11 ]

Can you try 1.9.1 - its available on the download page.

Also - 1.9.0 is unstable, so not intended for production.

Comment by Greg Studer [ 26/Jul/11 ]

This may already be fixed in 1.9.1, quick testing doesn't reproduce the null-ptr dereference.

Generated at Thu Feb 08 03:03:10 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.