Mongo unresponsive during "old journal file will be removed"

618 views
Skip to first unread message

Mark Horstmeier

unread,
Apr 18, 2012, 8:10:51 PM4/18/12
to mongodb-user
When removing objects from a collection (many, many) I get this
message:
Wed Apr 18 17:43:58 [conn22408] old journal file will be removed: /var/
lib/mongo/journal/j._19
Wed Apr 18 17:43:58 [initandlisten] connection accepted from
10.1.0.2:57213 #22432
Wed Apr 18 17:43:59 [initandlisten] connection accepted from
10.1.0.2:53820 #22433
Wed Apr 18 17:43:59 [conn22408] old journal file will be removed: /var/
lib/mongo/journal/j._20
Wed Apr 18 17:43:59 [snapshotthread] cpu: elapsed:4004 writelock: 39%

For the next few minutes, my mongostat looks like this:

insert query update delete getmore command flushes mapped vsize
res faults locked % idx miss % qr|qw ar|aw netIn netOut conn
set repl time
0 0 0 0 0 3 0 56.2g 113g
9.08g 0 0 0 71|102 70|104 330b 1k 191
KNS M 17:53:46
0 0 0 0 0 1 0 56.2g 113g
9.08g 0 0 0 71|102 70|104 62b 1k 191
KNS M 17:53:47
0 0 0 0 0 4 0 56.2g 113g
9.08g 0 0 0 71|102 70|104 393b 2k 192
KNS M 17:53:48
0 0 0 0 0 1 0 56.2g 113g
9.08g 0 0 0 71|102 70|104 62b 1k 192
KNS M 17:53:49

Approximately when mongo starts responding, the log looks like this:
Wed Apr 18 17:49:08 [conn22408] DR101 latency warning on journal file
open 309182ms
Wed Apr 18 17:49:08 [conn22114] SocketException handling request,
closing client connection: 9001 socket exception [2] server
[10.1.0.2:53241]
Wed Apr 18 17:49:08 [conn22428] SocketException handling request,
closing client connection: 9001 socket exception [2] server
[10.1.0.2:57184]
..
Wed Apr 18 17:49:09 [conn22408] ClientCursor::find(): cursor not found
in map 8371761198641609067 (ok after a drop)
killcursors: found 0 of 1
Wed Apr 18 17:49:09 [conn22408] end connection XX.XX.XX.XX:45381

Does this happen every time a journal file is removed? How do I keep
this from happening?


Eliot Horowitz

unread,
Apr 18, 2012, 8:22:22 PM4/18/12
to mongod...@googlegroups.com
What filesystem is the data living on?
What version of mongod?

I've seen this before on ext3 and older versions of mongo.

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

Mark Horstmeier

unread,
Apr 19, 2012, 11:37:38 AM4/19/12
to mongodb-user
v2.0.0
/dev/mapper/VolGroup01-LogVol01 on /var/lib/mongo type ext4
(rw,noatime,nodiratime)

Other info which may be pertinent mongodb is running in a VM attached
to a SAN for disk storage

Mark Horstmeier

unread,
Apr 20, 2012, 11:54:15 AM4/20/12
to mongodb-user
When an "old journal file" is being removed, what is the cause/process
that is happening? Are the journal's changes being pushed out to the
replicas? Have the replicas synched beyond the journal so it is no
longer necessary? Can an underachieving secondary impact performance
of the primary?

On Apr 18, 6:22 pm, Eliot Horowitz <el...@10gen.com> wrote:

Eliot Horowitz

unread,
Apr 21, 2012, 9:16:54 PM4/21/12
to mongod...@googlegroups.com
Can you try 2.0.4?

Journalling is orthogonal to replication.
The journal is just for on disk consistency and recovery after a system crash.

So secondaries won't impact the journal at all.

This issue is entirely with the latency of deleting large files.

Can you test a removing a non-mongo 1gb file?

Mark Horstmeier

unread,
Apr 24, 2012, 12:35:14 PM4/24/12
to mongod...@googlegroups.com
Upgraded to 2.04 and moved the journal to a separate partition.  Files get rotated without interrupting mongodb now.

Thanks
Reply all
Reply to author
Forward
0 new messages