[SERVER-4416] Assertion failure !loc.isNull() db/pdfile.cpp 1881 Created: 02/Dec/11  Updated: 17/Sep/12  Resolved: 04/Dec/11

Status: Closed
Project: Core Server
Component/s: Internal Code, Stability
Affects Version/s: 2.0.1
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: György Nagy Assignee: Aaron Staple
Resolution: Duplicate Votes: 0
Labels: assertion, server
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

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
Server: cpu: ~500 Mhz, 765 MB ram hosted on elastichosts.com.
OS: Ubuntu 11.10, kernel: 3.0.0-12-generic


Issue Links:
Duplicate
duplicates SERVER-4426 cryptic assertion when system.profile... Closed
Related
Operating System: Linux
Participants:

 Description   

We have a server with mongodb and apache2. Yesterday started to log these assertations that mainly occurs when in rockmongo i want to get the one of the db's collections, but i see in the log files that its occurs on 'normal' connections.

Fri Dec 2 08:44:07 [conn1631] authenticate:

{ authenticate: 1, user: "--", nonce: "--", key: "--" }

Fri Dec 2 08:44:08 [conn1631] authenticate:

{ authenticate: 1, user: "--", nonce: "--", key: "--" }

Fri Dec 2 08:44:08 [conn1631] command local.$cmd command: { $eval: CodeWScope( function ()

{ return db.getCollectionNames(); }, {}), args: {} } ntoreturn:1 reslen:50 16ms
Fri Dec 2 08:44:08 [conn1631] profile: warning ns local.system.profile does not exist
Fri Dec 2 08:44:08 [conn1631] command admin.$cmd command: { $eval: CodeWScope( function (){ return db.getCollectionNames(); }

, {}), args: {} } ntoreturn:1 reslen:92 15ms
Fri Dec 2 08:44:08 [conn1631] command tuner_db.$cmd command: { $eval: CodeWScope( function ()

{ return db.getCollectionNames(); }

, {}), args: {} } ntoreturn:1 reslen:864 16ms
Fri Dec 2 08:44:08 [conn1631] tuner_db Assertion failure !loc.isNull() db/pdfile.cpp 1881
0x57eeb6 0x589d6b 0x8a2746 0x777a3e 0x8890d4 0xa9c576 0x638937 0x7ffbf8332efc 0x7ffbf78cc89d
/usr/bin/mongod(_ZN5mongo12sayDbContextEPKc+0x96) [0x57eeb6]
/usr/bin/mongod(_ZN5mongo8assertedEPKcS1_j+0xfb) [0x589d6b]
/usr/bin/mongod() [0x8a2746]
/usr/bin/mongod(_ZN5mongo7profileERKNS_6ClientERNS_5CurOpE+0xc1e) [0x777a3e]
/usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xa04) [0x8890d4]
/usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x76) [0xa9c576]
/usr/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x638937]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7efc) [0x7ffbf8332efc]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7ffbf78cc89d]
Fri Dec 2 08:44:08 [conn1631] AssertionException handling request, closing client connection: 0 assertion db/pdfile.cpp:1881

.
.
.

Fri Dec 2 08:52:30 [conn1611] authenticate:

{ authenticate: 1, user: "--", nonce: "--", key: "--" }

Fri Dec 2 08:52:33 [conn1611] authenticate:

{ authenticate: 1, user: "--", nonce: "--", key: "--" }

Fri Dec 2 08:52:33 [conn1611] command tuner_db.$cmd command:

{ authenticate: 1, user: "--", nonce: "--", key: "--" }

ntoreturn:1 reslen:37 17ms
Fri Dec 2 08:52:33 [conn1611] tuner_db Assertion failure !loc.isNull() db/pdfile.cpp 1881
0x57eeb6 0x589d6b 0x8a2746 0x777a3e 0x8890d4 0xa9c576 0x638937 0x7ffbf8332efc 0x7ffbf78cc89d
/usr/bin/mongod(_ZN5mongo12sayDbContextEPKc+0x96) [0x57eeb6]
/usr/bin/mongod(_ZN5mongo8assertedEPKcS1_j+0xfb) [0x589d6b]
/usr/bin/mongod() [0x8a2746]
/usr/bin/mongod(_ZN5mongo7profileERKNS_6ClientERNS_5CurOpE+0xc1e) [0x777a3e]
/usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xa04) [0x8890d4]
/usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x76) [0xa9c576]
/usr/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x638937]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7efc) [0x7ffbf8332efc]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7ffbf78cc89d]
Fri Dec 2 08:52:33 [conn1611] AssertionException handling request, closing client connection: 0 assertion db/pdfile.cpp:1881

The differencies in mongodb.conf are the followings:
profile=1
slowms=10
nojournal=true
logappend=true
auth=true
noprealloc=true

Its a single mongodb instance, no relicas or sharding.
Current connections are around 30, with some query and update here and there, so there not so much load on mongodb(right now).



 Comments   
Comment by György Nagy [ 05/Dec/11 ]

Thank you.

Comment by Aaron Staple [ 04/Dec/11 ]

Yep, this is happening because system.profile is not capped. I've filed SERVER-4426 so that we can print a more user friendly error message.

Comment by György Nagy [ 04/Dec/11 ]

"Can you provide more information on one of the operations that triggered this failure"
Well, most of the time the db.getCollectionNames() from rockmongo asserted but but as i see basically everything(authentication, query, insert) asserted on this db that reached the 10ms runtime.
And i forgot to write it when i wrote this issue that the system.profile collection are create by hand after i saw in the log file the warnings: "profile: warning ns tuner_db.system.profile does not exist", and as i see now in the docs normally its a capped collection, but i created it as a regular collection. Can it be the source of the problem?

The db.system.profile.stats() output:
{
"ns" : "tuner_db.system.profile",
"count" : 29,
"size" : 7432,
"avgObjSize" : 256.2758620689655,
"storageSize" : 8192,
"numExtents" : 1,
"nindexes" : 1,
"lastExtentSize" : 8192,
"paddingFactor" : 1,
"flags" : 1,
"totalIndexSize" : 8176,
"indexSizes" :

{ "_id_" : 8176 }

,
"ok" : 1
}

""couldn't make room for new record" ..."
Not found in the logs.

Comment by Aaron Staple [ 03/Dec/11 ]

Hi György,

Can you provide more information on one of the operations that triggered this failure, and also run db.system.profile.stats() and send us the output?

Also, can you look back in your logs and see if there are any messages like this:

"couldn't make room for new record" ...

Thanks,
Aaron

Comment by György Nagy [ 02/Dec/11 ]

After turned profiling off, no assertation occured.

Comment by György Nagy [ 02/Dec/11 ]

One of the assert that occured on an insert:

Thu Dec 1 09:51:13 [conn737] authenticate:

{ authenticate: 1, user: "--", nonce: "--", key: "--" }

Thu Dec 1 09:51:13 [conn737] insert tuner_db.friend_action 68ms
Thu Dec 1 09:51:13 [conn737] tuner_db.friend_action Assertion failure !loc.isNull() db/pdfile.cpp 1881
0x57eeb6 0x589d6b 0x8a2746 0x777a3e 0x8890d4 0xa9c576 0x638937 0x7ffbf8332efc 0x7ffbf78cc89d
/usr/bin/mongod(_ZN5mongo12sayDbContextEPKc+0x96) [0x57eeb6]
/usr/bin/mongod(_ZN5mongo8assertedEPKcS1_j+0xfb) [0x589d6b]
/usr/bin/mongod() [0x8a2746]
/usr/bin/mongod(_ZN5mongo7profileERKNS_6ClientERNS_5CurOpE+0xc1e) [0x777a3e]
/usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xa04) [0x8890d4]
/usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x76) [0xa9c576]
/usr/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x638937]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7efc) [0x7ffbf8332efc]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7ffbf78cc89d]
Thu Dec 1 09:51:13 [conn737] AssertionException handling request, closing client connection: 0 assertion db/pdfile.cpp:1881

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