Another assertion error

[chris]

Hello,

I am running into a problem, that I cant add data (files) to the
database. I was using 2.0.2 before, when this error happened. Now I
tried 2.0.3-rc1, but the same error appears as soon as I try to add
more data.

The data directory is using 1.6 TB, but 1.1 TB are still free, so it
means it is kind of an internal error. I am using the Java driver to
access the DB. Below is the stack trace that I can see from the
terminal window:



Wed Feb 22 08:14:48 [journal] Assertion failure false db/
dur_journal.cpp 93
0x10007b7a3 0x100085f8c 0x1002b0843 0x10029f802 0x10029f8b6
0x10029fbcc 0x1002a0010 0x1002a049d 0x100292d03 0x100293834
0x100294736 0x100295b49 0x100617334 0x7fff821188bf 0x7fff8211bb75
0 mongod 0x000000010007b7a3
_ZN5mongo12sayDbContextEPKc + 195
1 mongod 0x0000000100085f8c
_ZN5mongo8assertedEPKcS1_j + 300
2 mongod 0x00000001002b0843
_ZN5mongo3dur17journalingFailureEPKc + 467
3 mongod 0x000000010029f802
_ZN5mongo3dur14findMMF_inlockEPvRm + 290
4 mongod 0x000000010029f8b6
_ZN5mongo3dur21prepBasicWrite_inlockERNS_14AlignedBuilderEPKNS0_11WriteIntentERNS_12RelativePathE
+ 70
5 mongod 0x000000010029fbcc
_ZN5mongo3dur21prepBasicWrite_inlockERNS_14AlignedBuilderEPKNS0_11WriteIntentERNS_12RelativePathE
+ 860
6 mongod 0x00000001002a0010
_ZN5mongo3dur15prepBasicWritesERNS_14AlignedBuilderE + 192
7 mongod 0x00000001002a049d
_ZN5mongo3dur13PREPLOGBUFFERERNS0_11JSectHeaderE + 237
8 mongod 0x0000000100292d03
_ZN5mongo3dur28_groupCommitWithLimitedLocksEv + 803
9 mongod 0x0000000100293834
_ZN5mongo3dur27groupCommitWithLimitedLocksEv + 36
10 mongod 0x0000000100294736
_ZN5mongo3dur2goEv + 822
11 mongod 0x0000000100295b49
_ZN5mongo3dur9durThreadEv + 601
12 mongod 0x0000000100617334
thread_proxy + 132
13 libsystem_c.dylib 0x00007fff821188bf
_pthread_start + 335
14 libsystem_c.dylib 0x00007fff8211bb75
thread_start + 13
Wed Feb 22 08:14:48 [journal] dbexception in groupCommitLL causing
immediate shutdown: 0 assertion db/dur_journal.cpp:93
Wed Feb 22 08:14:48 dur1
Wed Feb 22 08:14:48 Got signal: 6 (Abort trap: 6).

Wed Feb 22 08:14:48 [conn9] cloud2.fs_images.chunks Assertion failure
isOk() db/pdfile.h 300
0x10007b7a3 0x100085f8c 0x1003ff9fc 0x100410895 0x100412076
0x1003d99ac 0x1003e645f 0x1003e8a49 0x100610174 0x10014b092
0x100617334 0x7fff821188bf 0x7fff8211bb75
Wed Feb 22 08:14:48 Backtrace:
0x1005fd7b3 0x7fff8216ccfa 0x32aaaba7 0x7fff8210ba7a 0x1003d9360
0x100293920 0x100294736 0x100295b49 0x100617334 0x7fff821188bf
0x7fff8211bb75
0 mongod 0x00000001005fd7b3
_ZN5mongo10abruptQuitEi + 339
1 libsystem_c.dylib 0x00007fff8216ccfa _sigtramp
+ 26
2 ??? 0x0000000032aaaba7 0x0 +
850045863
3 libsystem_c.dylib 0x00007fff8210ba7a abort +
143
4 mongod 0x00000001003d9360
_ZN5mongo10mongoAbortEPKc + 96
5 mongod 0x0000000100293920
_ZN5mongo3dur27groupCommitWithLimitedLocksEv + 272
6 mongod 0x0000000100294736
_ZN5mongo3dur2goEv + 822
7 mongod 0x0000000100295b49
_ZN5mongo3dur9durThreadEv + 601
8 mongod 0x0000000100617334
thread_proxy + 132
9 libsystem_c.dylib 0x00007fff821188bf
_pthread_start + 335
10 libsystem_c.dylib 0x00007fff8211bb75
thread_start + 13

0 mongod 0x000000010007b7a3
_ZN5mongo12sayDbContextEPKc + 195
1 mongod 0x0000000100085f8c
_ZN5mongo8assertedEPKcS1_j + 300
2 mongod 0x00000001003ff9fc
_ZN5mongo26addRecordToRecListInExtentEPNS_6RecordENS_7DiskLocE + 476
3 mongod 0x0000000100410895
_ZN5mongo11DataFileMgr6insertEPKcPKvibbPb + 965
4 mongod 0x0000000100412076
_ZN5mongo11DataFileMgr16insertWithObjModEPKcRNS_7BSONObjEb + 70
5 mongod 0x00000001003d99ac
_ZN5mongo14checkAndInsertEPKcRNS_7BSONObjE + 172
6 mongod 0x00000001003e645f
_ZN5mongo14receivedInsertERNS_7MessageERNS_5CurOpE + 639
Logstream::get called in uninitialized state
7 mongod 0x00000001003e8a49
_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE
+ 4457
8 mongod 0x0000000100610174
_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE
+ 148
9 mongod 0x000000010014b092
_ZN5mongo3pms9threadRunEPNS_13MessagingPortE + 754
10 mongod 0x0000000100617334
thread_proxy + 132
11 libsystem_c.dylib 0x00007fff821188bf
_pthread_start + 335
12 libsystem_c.dylib 0x00007fff8211bb75
thread_start + 13
Wed Feb 22 08:14:48 [journal] ERROR: Client::shutdown not called:
journal
Logstream::get called in uninitialized state
Wed Feb 22 08:14:48 [conn9] insert cloud2.fs_images.chunks exception:
assertion db/pdfile.h:300 99ms
bash-3.2$

[Nat]

It sounds mmap fail. How much memory do you have? Can you also get ulimit -a?

--
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.

[chris]

Hello,

I am getting the following output (Mac OS X 10.7):

core file size          (blocks, -c) 0
data seg size           (kbytes, -d) 2000
file size               (blocks, -f) unlimited
max locked memory       (kbytes, -l) 2000
max memory size         (kbytes, -m) 2000
open files                      (-n) 10000
pipe size            (512 bytes, -p) 1
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 709
virtual memory          (kbytes, -v) 2000

This is my startup script:

ba-24:Applications$ cat startMongo
#!/bin/bash
cd Applications/mongodb-osx-x86_64-2.0.3-rc1/bin
ulimit -n 10000 -m 2000 -l 2000 -d 2000
./mongod --oplogSize=120000 --keyFile /Users/klukas/Applications/
mongoKey --dbpath /Volumes/3TB_2/MongoDB

The Mac has 32 GB RAM.

For testing I increased a number of parameters from 2000 to 5000 (and
then even to 50000), but the error still appears. Now the output is:

core file size (blocks, -c) 0
data seg size (kbytes, -d) 5000
file size (blocks, -f) unlimited
max locked memory (kbytes, -l) 5000
max memory size (kbytes, -m) 5000
open files (-n) 10000
pipe size (512 bytes, -p) 1
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 709
virtual memory (kbytes, -v) 5000


I hope this helps identifying the problem.


Greetings,

Chris

[chris]

Hello,

I further increased the limits:

core file size (blocks, -c) 0

data seg size (kbytes, -d) unlimited

file size (blocks, -f) unlimited

max locked memory (kbytes, -l) unlimited
max memory size (kbytes, -m) 9000000000
open files (-n) 9000

pipe size (512 bytes, -p) 1
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 709

virtual memory (kbytes, -v) 9000000000

The error still appears. I now tried to run without journal, then
mongod does not exit/crash, but for each insert I get still the
following error:

Wed Feb 22 11:04:14 [conn1] insert cloud2.fs_images.chunks exception:
assertion db/pdfile.h:300 3ms
Wed Feb 22 11:04:14 [conn1] cloud2.fs_images.chunks Assertion failure

isOk() db/pdfile.h 300
0x10007b7a3 0x100085f8c 0x1003ff9fc 0x100410895 0x100412076
0x1003d99ac 0x1003e645f 0x1003e8a49 0x100610174 0x10014b092
0x100617334 0x7fff821188bf 0x7fff8211bb75

0 mongod 0x000000010007b7a3
_ZN5mongo12sayDbContextEPKc + 195
1 mongod 0x0000000100085f8c
_ZN5mongo8assertedEPKcS1_j + 300
2 mongod 0x00000001003ff9fc
_ZN5mongo26addRecordToRecListInExtentEPNS_6RecordENS_7DiskLocE + 476
3 mongod 0x0000000100410895
_ZN5mongo11DataFileMgr6insertEPKcPKvibbPb + 965
4 mongod 0x0000000100412076
_ZN5mongo11DataFileMgr16insertWithObjModEPKcRNS_7BSONObjEb + 70
5 mongod 0x00000001003d99ac
_ZN5mongo14checkAndInsertEPKcRNS_7BSONObjE + 172
6 mongod 0x00000001003e645f
_ZN5mongo14receivedInsertERNS_7MessageERNS_5CurOpE + 639

7 mongod 0x00000001003e8a49
_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE
+ 4457
8 mongod 0x0000000100610174
_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE
+ 148
9 mongod 0x000000010014b092
_ZN5mongo3pms9threadRunEPNS_13MessagingPortE + 754
10 mongod 0x0000000100617334
thread_proxy + 132
11 libsystem_c.dylib 0x00007fff821188bf
_pthread_start + 335
12 libsystem_c.dylib 0x00007fff8211bb75
thread_start + 13

Wed Feb 22 11:04:14 [conn1] insert cloud2.fs_images.chunks exception:
assertion db/pdfile.h:300 3ms

[Nat]

What is your journal size? The journal requires some memory so it could fail if you don't give enough memory. Can you try to start it up without memory limit?

-----Original Message-----
From: chris <christia...@googlemail.com>
Sender: mongod...@googlegroups.com
Date: Wed, 22 Feb 2012 02:09:22
To: mongodb-user<mongod...@googlegroups.com>
Reply-To: mongod...@googlegroups.com

[chris]

I tried without journal and with journaling with the following startup
command (removed defined size of oplog):

./mongod --keyFile /Users/klukas/Applications/mongoKey --dbpath /
Volumes/3TB_2/MongoDB

In both cases the error still appears. I don't know how I could
specify journal memory limits. But even without journaling error
appears, so it not really related to it.

[Nat]

I mean changing ulimit to have really high numbers.

-----Original Message-----
From: chris <christia...@googlemail.com>
Sender: mongod...@googlegroups.com
Date: Wed, 22 Feb 2012 02:26:12
To: mongodb-user<mongod...@googlegroups.com>
Reply-To: mongod...@googlegroups.com
Subject: [mongodb-user] Re: Another assertion error

[chris]

I added a few more zeros to the limits and now get this:

core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
file size (blocks, -f) unlimited
max locked memory (kbytes, -l) unlimited

max memory size (kbytes, -m) unlimited
open files (-n) 10000

pipe size (512 bytes, -p) 1
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 709

virtual memory (kbytes, -v) unlimited

Max user processes and stack size could not be increased. Open file
limit is also near the maximum.

Still the same problem :-/

[Nat]

- Are you sure that your ulimit is actually set properly?  With journaling, it shouldn't take memory much more than without journaling. (2-3GB of committed memory at most) 

- Did you get the error right away? 

- What's the reading in "top" before it crashes?

[chris]

> - Are you sure that your ulimit is actually set properly?  With journaling,
> it shouldn't take memory much more than without journaling. (2-3GB of
> committed memory at most)

At least the maximum file number needs to be set, as the database is
currently using about than 820 files. Without the ulimit-setting the
data can not be read or processed, so this limit is set correctly by
the ulimit command. The other parameters are most likely also set. The
error appears with or without journaling, I think there is no problem
with RAM utilization, perhaps some internal pointers or structures are
exhausted or too large.

> - Did you get the error right away?

I get the error as soon as a binary file is added to the file
collection, before a larger number of smaller normal objects are added
to the database. Perhaps there is a limit on the number of entries per
collection?!

> - What's the reading in "top" before it crashes?

If I start freshly, the memory requirements are very low, the error
appears when only about 2 GB are loaded ("virtual mem" column in the
activity monitor). Before, the database worked fine while using more
than 20 GB memory (allocated) and "virtual mem" even much much more
memory. Actually I'd be happy to find out how to limit the resident
memory consumption, because on Mac OS X and Windows 7 the computers
can hardly be used for other things once the free memory is used up
(but this is only side problem, not related to this kind of bug).

[chris]

When I just issue "db.stats()", the same error appears: "Assertion
failure isOk() db/pdfile.h 300"

I tried db.fs_images.chunks.find().count()
and the result is
6570692
Which seems to be no special number.

>>>>>>>>>>>>>

./startMongo

core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
file size (blocks, -f) unlimited
max locked memory (kbytes, -l) unlimited
max memory size (kbytes, -m) unlimited
open files (-n) 10000
pipe size (512 bytes, -p) 1
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 709
virtual memory (kbytes, -v) unlimited

Wed Feb 22 13:54:11 [initandlisten] MongoDB starting : pid=573
port=27017 dbpath=/Volumes/3TB_2/MongoDB 64-bit host=ba-24.ipk-
gatersleben.de
Wed Feb 22 13:54:11 [initandlisten] db version v2.0.3-rc1, pdfile
version 4.5
Wed Feb 22 13:54:11 [initandlisten] git version:
ac5eb821bb87bc22fe1b4c9ea763dceec0df9d9a
Wed Feb 22 13:54:11 [initandlisten] build info: Darwin erh2.10gen.cc
9.8.0 Darwin Kernel Version 9.8.0: Wed Jul 15 16:55:01 PDT 2009;
root:xnu-1228.15.4~1/RELEASE_I386 i386 BOOST_LIB_VERSION=1_40
Wed Feb 22 13:54:11 [initandlisten] options: { dbpath: "/Volumes/3TB_2/
MongoDB", keyFile: "/Users/klukas/Applications/mongoKey", oplogSize:
120000 }
Wed Feb 22 13:54:11 [initandlisten] journal dir=/Volumes/3TB_2/MongoDB/
journal
Wed Feb 22 13:54:11 [initandlisten] recover begin
Wed Feb 22 13:54:11 [initandlisten] recover lsn: 164136
Wed Feb 22 13:54:11 [initandlisten] recover /Volumes/3TB_2/MongoDB/
journal/j._0
Wed Feb 22 13:54:11 [initandlisten] recover skipping application of
section seq:54576 < lsn:164136
Wed Feb 22 13:54:11 [initandlisten] recover skipping application of
section seq:109346 < lsn:164136
Wed Feb 22 13:54:12 [initandlisten] recover cleaning up
Wed Feb 22 13:54:12 [initandlisten] removeJournalFiles
Wed Feb 22 13:54:12 [initandlisten] recover done
Wed Feb 22 13:54:12 [websvr] admin web console waiting for connections
on port 28017
Wed Feb 22 13:54:12 [initandlisten] waiting for connections on port
27017
Wed Feb 22 13:54:13 [initandlisten] connection accepted from
192.168.34.209:60002 #1
Wed Feb 22 13:54:14 [initandlisten] connection accepted from
194.94.140.213:51615 #2
Wed Feb 22 13:54:15 [initandlisten] connection accepted from
194.94.138.103:53776 #3
Wed Feb 22 13:54:16 [initandlisten] connection accepted from
194.94.140.218:60325 #4
Wed Feb 22 13:54:22 [initandlisten] connection accepted from
127.0.0.1:49549 #5
Wed Feb 22 13:54:35 [conn5] authenticate: { authenticate: 1.0, user:
"iap24", nonce: "c95e78533e96e1cf", key:
"37e0c8a6ba075d6ca3da4cc73e5230f1" }
Wed Feb 22 13:55:12 [clientcursormon] mem (MB) res:66 virt:3298260
mapped:1647868
Wed Feb 22 13:55:55 [conn5] cloud2 Assertion failure isOk() db/
pdfile.h 300
0x10007b7a3 0x100085f8c 0x1003b2952 0x100501fd5 0x1004e8ec7
0x1004ea347 0x1004a6874 0x1004a8fb4 0x1003db2df 0x1003e7e5a
0x100610174 0x10014b092 0x100617334 0x7fff8c3968bf 0x7fff8c399b75

0 mongod 0x000000010007b7a3
_ZN5mongo12sayDbContextEPKc + 195
1 mongod 0x0000000100085f8c
_ZN5mongo8assertedEPKcS1_j + 300

2 mongod 0x00000001003b2952
_ZNK5mongo16NamespaceDetails11storageSizeEPiPNS_16BSONArrayBuilderE +
3634
3 mongod 0x0000000100501fd5
_ZN5mongo7DBStats3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb +
485
4 mongod 0x00000001004e8ec7
_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb
+ 2343
5 mongod 0x00000001004ea347
_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi
+ 2599
6 mongod 0x00000001004a6874
_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi
+ 52
7 mongod 0x00000001004a8fb4
_ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_ +
4820
8 mongod 0x00000001003db2df
_ZN5mongo13receivedQueryERNS_6ClientERNS_10DbResponseERNS_7MessageE +
623
9 mongod 0x00000001003e7e5a
_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE
+ 1402
10 mongod 0x0000000100610174
_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE
+ 148
11 mongod 0x000000010014b092
_ZN5mongo3pms9threadRunEPNS_13MessagingPortE + 754
12 mongod 0x0000000100617334
thread_proxy + 132
13 libsystem_c.dylib 0x00007fff8c3968bf
_pthread_start + 335
14 libsystem_c.dylib 0x00007fff8c399b75
thread_start + 13
Wed Feb 22 13:55:55 [conn5] command cloud2.$cmd command: { dbstats:
1.0, scale: undefined } ntoreturn:1 reslen:96 442ms

[Nat]

For this one, someone reported this a few times under Mac already.

https://jira.mongodb.org/browse/SERVER-4198 

Can you try to repair database and restart to see whether it makes any differences? (It could take a long while :-) )