Server crashed when running mapreduce
Kent Sibilev
inserting documents with strings that are invalid according to UTF-8
encoding. Here is an example,
$ irb
irb(main):001:0> require 'mongo'
=> true
irb(main):002:0> d = Mongo::Connection.new.db('test')
=> #<Mongo::DB:....>
irb(main):003:0> str = "123\xD9"
=> "123\xD9"
irb(main):004:0> str.encoding
=> #<Encoding:UTF-8>
irb(main):005:0> str.valid_encoding?
=> false
irb(main):006:0> d['test'].insert(:text => str)
=> BSON::ObjectId('4d8a9d33f9cff1783b000001')
irb(main):007:0> exit
$ mongo
MongoDB shell version: 1.8.0
connecting to: test
> db.test.findOne()
Wed Mar 23 21:24:20 decode failed. probably invalid utf-8 string [123?]
Wed Mar 23 21:24:20 why: InternalError: buffer too small
Wed Mar 23 21:24:20 Error: invalid utf8 shell/utils.js:853
When we ran a map/reduce procedure on our sharded database, Mongo
threw this exception on one of our three shards:
Wed Mar 23 18:55:05 [conn45] decode failed. probably invalid utf-8
string [XXXXXXXXXXXXXXXXXXXXXXXXXXXXX<D9>]
Wed Mar 23 18:55:05 [conn45] why: InternalError: buffer too small
Wed Mar 23 18:55:05 [conn45] vhn_bap.patient_exts Assertion failure
JS_GetProperty( _context , o , field , &v ) scripting/engine_spidermo
nkey.cpp 728
0x5512de 0x562ce1 0x61ddd1 0x625d10 0x626a3a 0x61b310 0x953cd3
0x94a53c 0x953cd3 0x966ccd 0x953d60 0x9541a9 0x911b32 0x62535c
0x8039c0 0x8
13573 0x7dc1fe 0x7ddb21 0x645565 0x64addc
/usr/local/mongodb/bin/mongod(_ZN5mongo12sayDbContextEPKc+0xae) [0x5512de]
/usr/local/mongodb/bin/mongod(_ZN5mongo8assertedEPKcS1_j+0x111) [0x562ce1]
/usr/local/mongodb/bin/mongod(_ZN5mongo9Convertor11getPropertyEP8JSObjectPKc+0x51)
[0x61ddd1]
/usr/local/mongodb/bin/mongod(_ZN5mongo9Convertor8toObjectEP8JSObjectRKNS_13TraverseStackE+0x470)
[0x625d10]
/usr/local/mongodb/bin/mongod(_ZN5mongo9Convertor6appendERNS_14BSONObjBuilderESslNS_8BSONTypeERKNS_13TraverseStackE+0x5ca)
[0x626a3a]
/usr/local/mongodb/bin/mongod(_ZN5mongo13native_helperEP9JSContextP8JSObjectjPlS4_+0x1b0)
[0x61b310]
/usr/local/mongodb/bin/mongod(js_Invoke+0xe65) [0x953cd3]
/usr/local/mongodb/bin/mongod [0x94a53c]
/usr/local/mongodb/bin/mongod(js_Invoke+0xe65) [0x953cd3]
/usr/local/mongodb/bin/mongod(js_Interpret+0x11433) [0x966ccd]
/usr/local/mongodb/bin/mongod(js_Interpret+0x11433) [0x966ccd]
/usr/local/mongodb/bin/mongod(js_Invoke+0xef2) [0x953d60]
/usr/local/mongodb/bin/mongod(js_InternalInvoke+0x189) [0x9541a9]
/usr/local/mongodb/bin/mongod(JS_CallFunction+0x56) [0x911b32]
0x5512de 0x562ce1 0x61ddd1 0x625d10 0x626a3a 0x61b310 0x953cd3
0x94a53c 0x953cd3 0x966ccd 0x953d60 0x9541a9 0x911b32 0x62535c
0x8039c0 0x8
13573 0x7dc1fe 0x7ddb21 0x645565 0x64addc
/usr/local/mongodb/bin/mongod(_ZN5mongo12sayDbContextEPKc+0xae) [0x5512de]
/usr/local/mongodb/bin/mongod(_ZN5mongo8assertedEPKcS1_j+0x111) [0x562ce1]
/usr/local/mongodb/bin/mongod(_ZN5mongo9Convertor11getPropertyEP8JSObjectPKc+0x51)
[0x61ddd1]
/usr/local/mongodb/bin/mongod(_ZN5mongo9Convertor8toObjectEP8JSObjectRKNS_13TraverseStackE+0x470)
[0x625d10]
/usr/local/mongodb/bin/mongod(_ZN5mongo9Convertor6appendERNS_14BSONObjBuilderESslNS_8BSONTypeERKNS_13TraverseStackE+0x5ca)
[0x626a3a]
/usr/local/mongodb/bin/mongod(_ZN5mongo13native_helperEP9JSContextP8JSObjectjPlS4_+0x1b0)
[0x61b310]
/usr/local/mongodb/bin/mongod(js_Invoke+0xe65) [0x953cd3]
/usr/local/mongodb/bin/mongod [0x94a53c]
/usr/local/mongodb/bin/mongod(js_Invoke+0xe65) [0x953cd3]
/usr/local/mongodb/bin/mongod(js_Interpret+0x11433) [0x966ccd]
/usr/local/mongodb/bin/mongod(js_Invoke+0xef2) [0x953d60]
/usr/local/mongodb/bin/mongod(js_InternalInvoke+0x189) [0x9541a9]
var mpi = this.mpi;
var diag_type = this.diag_ty..., reduce: function (key, vals) {
Then we used Ruby driver to fix those documents with the invalid
encoding and restarted our map/reduce. That killed all three nodes
with the following postmortem:
Wed Mar 23 19:24:32 Got signal: 6 (Aborted).
Wed Mar 23 19:24:32 [conn41] end connection XX.XXX.XXX.XXX:37985
Wed Mar 23 19:24:32 Backtrace:
0x7ddb21 0x645565 0x64addc 0x757f15 0x75a440 0x8a617e
/usr/local/mongodb/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x8a5359]
/lib64/libc.so.6 [0x326da302d0]
/lib64/libc.so.6(gsignal+0x35) [0x326da30265]
/lib64/libc.so.6(abort+0x110) [0x326da31d10]
/usr/local/mongodb/bin/mongod [0x9d2b79]
/usr/local/mongodb/bin/mongod(js_Execute+0x37b) [0x9547ed]
/usr/local/mongodb/bin/mongod(JS_EvaluateUCScriptForPrincipals+0xb5) [0x911a83]
/usr/local/mongodb/bin/mongod(JS_EvaluateUCScript+0x5a) [0x9119cc]
/usr/local/mongodb/bin/mongod(JS_EvaluateScript+0x80) [0x9118b5]
/usr/local/mongodb/bin/mongod(_ZN5mongo7SMScope4execERKNS_10StringDataERKSsbbbi+0x10d)
[0x62282d]
/usr/local/mongodb/bin/mongod(_ZN5mongo7SMScope12injectNativeEPKcPFNS_7BSONObjERKS3_E+0x253)
[0x61ebd3]
/usr/local/mongodb/bin/mongod(_ZN5mongo2mr5State4initEv+0xf6) [0x808b36]
/usr/local/mongodb/bin/mongod(_ZN5mongo2mr16MapReduceCommand3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0x17c)
[0x81321c]
/usr/local/mongodb/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x5ae)
[0x7dc1fe]
/usr/local/mongodb/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x831)
[0x7ddb21]
/usr/local/mongodb/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x35)
[0x645565]
/usr/local/mongodb/bin/mongod(_ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0x31ac)
[0x64addc]
/usr/local/mongodb/bin/mongod [0x757f15]
/usr/local/mongodb/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_8SockAddrE+0x5b0)
[0x75a440]
/usr/local/mongodb/bin/mongod(_ZN5mongo10connThreadEPNS_13MessagingPortE+0x21e)
[0x8a617e]
Wed Mar 23 19:24:32 dbexit:
Wed Mar 23 19:24:32 [conn45] shutdown: going to close listening sockets...
Wed Mar 23 19:24:32 [conn45] closing listening socket: 5
Wed Mar 23 19:24:32 [conn45] closing listening socket: 6
Wed Mar 23 19:24:32 [conn45] closing listening socket: 7
Wed Mar 23 19:24:32 [conn45] closing listening socket: 8
Wed Mar 23 19:24:32 [conn45] removing socket file: /tmp/mongodb-27018.sock
Wed Mar 23 19:24:33 [conn45] removing socket file: /tmp/mongodb-28018.sock
Wed Mar 23 19:24:33 [conn45] shutdown: going to flush diaglog...
Wed Mar 23 19:24:33 [conn45] shutdown: going to close sockets...
Wed Mar 23 19:24:33 [conn45] shutdown: waiting for fs preallocator...
Wed Mar 23 19:24:33 [conn45] shutdown: closing all files...
Wed Mar 23 19:24:33 Got signal: 11 (Segmentation fault).
Wed Mar 23 19:24:33 Backtrace:
0x75a440 0x8a617e 0x8b92d0 0x326e60673d 0x326dad3d1d
/usr/local/mongodb/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x8a5359]
/lib64/libc.so.6 [0x326da302d0]
63e1]
) [0x68a7a8]
1) [0x68a8d1]
/usr/local/mongodb/bin/mongod(_ZNK5mongo11BtreeBucket7unindexENS_7DiskLocERNS_12IndexDetailsERKNS_7BSONObjES1_+0x2ac)
[0x68b21c]
/usr/local/mongodb/bin/mongod [0x76f88e]
/usr/local/mongodb/bin/mongod(_ZN5mongo11DataFileMgr12deleteRecordEPKcPNS_6RecordERKNS_7DiskLocEbb+0x140)
[0x772710]
/usr/local/mongodb/bin/mongod(_ZN5mongo7Helpers11removeRangeERKSsRKNS_7BSONObjES5_bbPNS0_14RemoveCallbackE+0x876)
[0x74be66]
/usr/local/mongodb/bin/mongod(_ZN5mongo16MoveChunkCommand3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0x8267)
[0x878887]
/usr/local/mongodb/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x5ae)
[0x7dc1fe]
/usr/local/mongodb/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x831)
[0x7ddb21]
/usr/local/mongodb/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x35)
[0x645565]
/usr/local/mongodb/bin/mongod(_ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0x31ac)
[0x64addc]
/usr/local/mongodb/bin/mongod [0x757f15]
/usr/local/mongodb/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_8SockAddrE+0x5b0)
[0x75a440]
/usr/local/mongodb/bin/mongod(_ZN5mongo10connThreadEPNS_13MessagingPortE+0x21e)
[0x8a617e]
/usr/local/mongodb/bin/mongod(thread_proxy+0x80) [0x8b92d0]
/lib64/libpthread.so.0 [0x326e60673d]
/lib64/libc.so.6(clone+0x6d) [0x326dad3d1d]
Wed Mar 23 19:24:33 dbexit: ; exiting immediately
Wed Mar 23 19:24:33 Got signal: 11 (Segmentation fault).
Wed Mar 23 19:24:33 Backtrace:
8b5 0x62282d 0x61ebd3 0x808b36 0x81321c 0x7dc1fe 0x7ddb21
/usr/local/mongodb/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x8a5359]
/lib64/libc.so.6 [0x326da302d0]
/usr/local/mongodb/bin/mongod(_ZN5mongo9MongoFile13closeAllFilesERSt18basic_stringstreamIcSt11char_traitsIcESaIcEE+0xbc)
[0x548a6c]
/usr/local/mongodb/bin/mongod(_ZN5mongo14shutdownServerEv+0x4b8) [0x754158]
/usr/local/mongodb/bin/mongod(_ZN5mongo6dbexitENS_8ExitCodeEPKcb+0x1f4)
[0x7549d4]
/usr/local/mongodb/bin/mongod(_ZN5mongo10abruptQuitEi+0x4f6) [0x8a54b6]
/lib64/libc.so.6 [0x326da302d0]
/lib64/libc.so.6(gsignal+0x35) [0x326da30265]
/lib64/libc.so.6 [0x326da302d0]
/lib64/libc.so.6(gsignal+0x35) [0x326da30265]
/lib64/libc.so.6(abort+0x110) [0x326da31d10]
/usr/local/mongodb/bin/mongod [0x9d2b79]
/usr/local/mongodb/bin/mongod(js_Execute+0x37b) [0x9547ed]
/usr/local/mongodb/bin/mongod(JS_EvaluateUCScriptForPrincipals+0xb5) [0x911a83]
/usr/local/mongodb/bin/mongod(JS_EvaluateUCScript+0x5a) [0x9119cc]
/usr/local/mongodb/bin/mongod(JS_EvaluateScript+0x80) [0x9118b5]
/usr/local/mongodb/bin/mongod(_ZN5mongo7SMScope4execERKNS_10StringDataERKSsbbbi+0x10d)
[0x62282d]
/usr/local/mongodb/bin/mongod(_ZN5mongo7SMScope12injectNativeEPKcPFNS_7BSONObjERKS3_E+0x253)
[0x61ebd3]
/usr/local/mongodb/bin/mongod(_ZN5mongo2mr5State4initEv+0xf6) [0x808b36]
/usr/local/mongodb/bin/mongod(_ZN5mongo2mr16MapReduceCommand3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0x17c)
[0x81321c]
/usr/local/mongodb/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x5ae)
[0x7dc1fe]
/usr/local/mongodb/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x831)
[0x7ddb21]
Wed Mar 23 19:24:33 ERROR: Client::~Client _context should be null but
is not; client:conn
Hope it helps to diagnose the problem.
Kent Sibilev.
Kyle Banker
Thanks for the report. Oddly enough, based a quick test, the driver
catches the string you provided in Ruby 1.8 but not in 1.9. I've
created a JIRA for tracking, which you can watch. Will put out a fix
ASAP.
http://jira.mongodb.org/browse/RUBY-253
Kyle
> --
> You received this message because you are subscribed to the Google Groups "mongodb-user" group.
> To post to this group, send email to mongod...@googlegroups.com.
> To unsubscribe from this group, send email to mongodb-user...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/mongodb-user?hl=en.
>
>
Kyle Banker
There was definitely an issue serializing UTF-8 in Ruby 1.9. It's been
fix in the just-released driver v1.3.0.rc0. Please feel free to test.
Kyle