[SERVER-6860] Assertion: 13548:BufBuilder grow() > 64MB when trying to profile a huge document Created: 26/Aug/12  Updated: 27/Jul/17  Resolved: 19/Sep/12

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 2.0.6
Fix Version/s: 2.3.0

Type: Bug Priority: Major - P3
Reporter: Ran Tavory Assignee: Randolph Tan
Resolution: Done Votes: 1
Labels: crash
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Linux ubuntu on AWS

$ uname -a
Linux domU-...-virtual #42-Ubuntu SMP Mon Apr 11 04:06:34 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux

$ cat /etc/issue
Ubuntu 11.04


Issue Links:
Depends
Related
is related to SERVER-7062 profile4.js buildbot failures Closed
Operating System: Linux
Participants:
Case:

 Description   

When running my app, under what's probably relatively heavy load, after a few hours or maybe even days, the server crashed with the following:

Sun Aug 26 13:01:50 [clientcursormon] mem (MB) res:5841 virt:13977 mapped:6094                                                                                                                  [228/1807]
Sun Aug 26 13:02:00 [conn3696] Assertion: 13548:BufBuilder grow() > 64MB
0x5848a2 0x5056e6 0x895d9f 0x7796f8 0x88e17c 0xaa0bc8 0x6389f7 0x7f1d2268dd8c 0x7f1d21c37c2d 
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo11msgassertedEiPKc+0x112) [0x5848a2]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod() [0x5056e6]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZNK5mongo7OpDebug6appendERKNS_5CurOpERNS_14BSONObjBuilderE+0x2bf) [0x895d9f]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo7profileERKNS_6ClientERNS_5CurOpE+0x218) [0x7796f8]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x9fc) [0x88e17c]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x78) [0xaa0bc8]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x6389f7]
 /lib/x86_64-linux-gnu/libpthread.so.0(+0x6d8c) [0x7f1d2268dd8c]
 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f1d21c37c2d]
Sun Aug 26 13:02:00 [conn3696] Assertion: 13548:BufBuilder grow() > 64MB
0x5848a2 0x5056e6 0x509929 0x77a466 0x88e17c 0xaa0bc8 0x6389f7 0x7f1d2268dd8c 0x7f1d21c37c2d 
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo11msgassertedEiPKc+0x112) [0x5848a2]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod() [0x5056e6]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo14BSONObjBuilderD1Ev+0x259) [0x509929]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo7profileERKNS_6ClientERNS_5CurOpE+0xf86) [0x77a466]                                                                                                                                                                                      [205/1807]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x9fc) [0x88e17c]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x78) [0xaa0bc8]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x6389f7]
 /lib/x86_64-linux-gnu/libpthread.so.0(+0x6d8c) [0x7f1d2268dd8c]
 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f1d21c37c2d]
Sun Aug 26 13:02:00 terminate() called, printing stack:
0xa957de 0x7f1d2243a926 0x7f1d224398f9 0x7f1d2243a215 0x7f1d21ef544b 0x7f1d21ef58bb 0x5099f6 0x77a466 0x88e17c 0xaa0bc8 0x6389f7 0x7f1d2268dd8c 0x7f1d21c37c2d 
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo11myterminateEv+0x5e) [0xa957de]
 /usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0xb9926) [0x7f1d2243a926]
 /usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0xb88f9) [0x7f1d224398f9]
 /usr/lib/x86_64-linux-gnu/libstdc++.so.6(__gxx_personality_v0+0x235) [0x7f1d2243a215]
 /lib/x86_64-linux-gnu/libgcc_s.so.1(+0xf44b) [0x7f1d21ef544b]
 /lib/x86_64-linux-gnu/libgcc_s.so.1(_Unwind_Resume+0x8b) [0x7f1d21ef58bb]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo14BSONObjBuilderD1Ev+0x326) [0x5099f6]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo7profileERKNS_6ClientERNS_5CurOpE+0xf86) [0x77a466]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x9fc) [0x88e17c]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x78) [0xaa0bc8]                                                                                                                                     [181/1807]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x6389f7]
 /lib/x86_64-linux-gnu/libpthread.so.0(+0x6d8c) [0x7f1d2268dd8c]
 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f1d21c37c2d]
Sun Aug 26 13:02:00 Got signal: 6 (Aborted).
 
Sun Aug 26 13:02:00 Backtrace:
0xa95ce9 0x7f1d21b84d80 0x7f1d21b84d05 0x7f1d21b88ab6 0xa958ab 0x7f1d2243a926 0x7f1d224398f9 0x7f1d2243a215 0x7f1d21ef544b 0x7f1d21ef58bb 0x5099f6 0x77a466 0x88e17c 0xaa0bc8 0x6389f7 0x7f1d2268dd8c 0x7f1d21c37c2d 
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo10abruptQuitEi+0x3a9) [0xa95ce9]
 /lib/x86_64-linux-gnu/libc.so.6(+0x33d80) [0x7f1d21b84d80]
 /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35) [0x7f1d21b84d05]
 /lib/x86_64-linux-gnu/libc.so.6(abort+0x186) [0x7f1d21b88ab6]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo11myterminateEv+0x12b) [0xa958ab]
 /usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0xb9926) [0x7f1d2243a926]
 /usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0xb88f9) [0x7f1d224398f9]
 /usr/lib/x86_64-linux-gnu/libstdc++.so.6(__gxx_personality_v0+0x235) [0x7f1d2243a215]
 /lib/x86_64-linux-gnu/libgcc_s.so.1(+0xf44b) [0x7f1d21ef544b]
 /lib/x86_64-linux-gnu/libgcc_s.so.1(_Unwind_Resume+0x8b) [0x7f1d21ef58bb]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo14BSONObjBuilderD1Ev+0x326) [0x5099f6]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo7profileERKNS_6ClientERNS_5CurOpE+0xf86) [0x77a466]                                                                                                                                                                                      [158/1807]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x9fc) [0x88e17c]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x78) [0xaa0bc8]
 /home/ubuntu/mongodb-linux-x86_64-2.0.6/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x6389f7]
 /lib/x86_64-linux-gnu/libpthread.so.0(+0x6d8c) [0x7f1d2268dd8c]
 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f1d21c37c2d]
 
Logstream::get called in uninitialized state
Sun Aug 26 13:02:00 ERROR: Client::~Client _context should be null but is not; client:conn
Logstream::get called in uninitialized state
Sun Aug 26 13:02:00 ERROR: Client::shutdown not called: conn



 Comments   
Comment by auto [ 19/Sep/12 ]

Author:

{u'date': u'2012-08-30T14:00:30-07:00', u'email': u'randolph@10gen.com', u'name': u'Randolph Tan'}

Message: SERVER-6860 Assertion: 13548:BufBuilder grow() > 64MB when trying to profile a huge document

Changed objsize() to size()
Branch: master
https://github.com/mongodb/mongo/commit/f87f384fc21f3cc928d942c76a9ed1469cba60f5

Comment by auto [ 18/Sep/12 ]

Author:

{u'date': u'2012-09-18T14:02:26-07:00', u'email': u'randolph@10gen.com', u'name': u'Randolph Tan'}

Message: Revert "SERVER-6860 Assertion: 13548:BufBuilder grow() > 64MB when trying to profile a huge document"

This reverts commit c5382706fad324561e431bf3baa1321d9ace9433 because of SERVER-7062.
Branch: master
https://github.com/mongodb/mongo/commit/d89071b51774f31bc35416c077f868aa0e6dd2b5

Comment by auto [ 18/Sep/12 ]

Author:

{u'date': u'2012-08-30T14:00:30-07:00', u'email': u'randolph@10gen.com', u'name': u'Randolph Tan'}

Message: SERVER-6860 Assertion: 13548:BufBuilder grow() > 64MB when trying to profile a huge document
Branch: master
https://github.com/mongodb/mongo/commit/c5382706fad324561e431bf3baa1321d9ace9433

Comment by Ran Tavory [ 27/Aug/12 ]

sure, see inline...

On Mon, Aug 27, 2012 at 10:25 PM, A. Jesse Jiryu Davis (JIRA) <

my queries are small, what could grow, to some extent without limits, is
the insertion of objects of my type Session. I don't know if the profiler
lists the entire document inserted, which might be large in some cases, but
if it does, then this could be it.

The load is inserts, updates, commands and reads...
Here's a sample mongostat from this load

insert  query update delete getmore command flushes mapped  vsize    res
faults locked % idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
    17      1    787      0       0     912       0  11.9g  24.4g  2.75g
  38     26.4          0     10|36   11|36     6m   118k   113   19:29:42
    24      3    940      0       0    1106       0  11.9g  24.4g  2.77g
  42     26.5          0      0|36   13|37     7m   142k   113   19:29:43
    25      0    937      0       0    1103       0  11.9g  24.4g  2.78g
  21     26.8          0      0|23   12|24     7m   159k   113   19:29:44
    29      0   1101      0       0    1278       0  11.9g  24.4g  2.73g
  31     35.7          0     10|44   11|44     8m   164k   113   19:29:45
    31      0   1187      0       0    1388       0  11.9g  24.4g  2.76g
  32     32.7          0      0|52   11|52     8m   177k   113   19:29:46
    38      1   1119      0       1    1358       0  11.9g  24.4g  2.74g
  38     36.7          0      2|10   11|11     9m   179k   113   19:29:47
    45      0   1405      0       0    1638       0  11.9g  24.4g  2.77g
  50     38.6          0      0|31   11|32     9m   209k   113   19:29:48
    33      0   1129      0       0    1318       0  11.9g  24.4g  2.74g
  41     36.8          0      0|44   10|44    10m   198k   113   19:29:49
    38      1   1106      0       0    1346       0  11.9g  24.4g  2.76g
  30     31.8          0       2|1     8|1     9m   552k   113   19:29:50

you have profiling turned on with setProfilingLevel? What driver are you

Yes, profiling is on. I even created this neat gist...
https://gist.github.com/3433277

and if there are then it's my bug (but I don't thing there are...)

I'm using the java 2.8.0 driver with morphia 0.99

cheers


/Ran
http://tavory.com

Comment by A. Jesse Jiryu Davis [ 27/Aug/12 ]

Hi Ran, thanks for reporting this. I think what we're seeing is that the server crashes when it tries to assemble a document to insert into system.profile that exceeds 64MB.

Can you give some more detail about your usage? E.g., what kind of load are you generating: inserts, updates, commands, ...? Do you have profiling turned on with setProfilingLevel? What driver are you using? Are you generating extremely large query specifications, e.g.:

db.collection.find({_id: {$in: [ ... millions of ids ... ] }})

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