Mongo db gets stuck at insert

[Moshe Shperling]

Hi guys! I am using c# and running mongodb on windows server 2008.

I have usually a few lengthy processes running, that operate with a quite a large amount of data. Recently i started experiencing a rather strange issue - mongo gets stuck at some insert (it can be different types of inserts), it remains frozen for quite a while (it stay like this for a few hours!!). 

Any help, please.

[Asya Kamsky]

Moshe,

There is not enough information here to even speculate about what might be happening but since you say it gets stuck in this state for a while it should be straight forward to gather some useful information when it happens next.

What is in the logs at this time?

What is the output of db.currentOp() at that time?  

What does ProcMon show the process doing at that point?

What version of MongoDB and C# driver are you using?  What writeConcern are you using?

What are you inserting?   Are these large documents?  What sort of disk is dbpath on? What options are you starting 'mongod' process with?  Is this a replica set?

Asya

--
--
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
See also the IRC channel -- freenode.net#mongodb
 
---
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Moshe Shperling]

hi 

thanks for your reply.

I must admit that i am quite a beginner with mongodb. 

this is the log entry

Wed Dec 25 17:26:18.651 [conn31677] insert inventory.logs ninserted:1 keyUpdates:0 locks(micros) w:116 231ms

Wed Dec 25 17:26:41.917 [conn31684] end connection 127.0.0.1:15531 (57 connections now open)

Wed Dec 25 17:26:41.917 [conn31677] end connection 127.0.0.1:15417 (56 connections now open)

Wed Dec 25 17:26:42.512 [conn31686] end connection 127.0.0.1:15538 (55 connections now open)

Wed Dec 25 17:26:42.588 [conn31675] end connection 127.0.0.1:15414 (55 connections now open)

Wed Dec 25 17:27:01.504 [initandlisten] connection accepted from 127.0.0.1:15662 #31700 (55 connections now open)

Wed Dec 25 17:27:01.541 [conn31700]  authenticate db: admin { authenticate: 1, user: "contigo", nonce: "790c024dbd408bc8", key: "22d6a8f9896a027574c68fd759176ebd" }

Wed Dec 25 17:27:09.201 [conn31700] insert inventory.ca_prereprice_result ninserted:1 keyUpdates:0 locks(micros) w:34 287ms

Wed Dec 25 17:27:09.521 [conn31700] insert inventory.ca_prereprice_result ninserted:1 keyUpdates:0 locks(micros) w:36 218ms

Wed Dec 25 17:27:09.994 [conn31103] end connection 10.0.0.88:62912 (54 connections now open)

Wed Dec 25 17:27:09.995 [initandlisten] connection accepted from 10.0.0.88:15664 #31701 (55 connections now open)

Wed Dec 25 17:27:09.996 [conn31701]  authenticate db: admin { authenticate: 1, user: "excelladdin", nonce: "5d23b79c9a6f249e", key: "105af151a8efe22938c8e1d8301b7c2a" }

Wed Dec 25 17:27:11.651 [initandlisten] connection accepted from 127.0.0.1:15665 #31702 (56 connections now open)

Wed Dec 25 17:27:11.652 [conn31702]  authenticate db: admin { authenticate: 1, user: "contigo", nonce: "fdc46125b2b1d465", key: "d51c63266ca303884a40b4293759cafe" }

Wed Dec 25 17:27:20.373 [conn31702] getmore inventory.products query: { isautopriced: "TRUE", totalpooled: { $gt: "0" }, classification: { $in: [ "Watch Straps", "Watches" ] } } cursorid:760564363800419719 ntoreturn:0 keyUpdates:0 numYields: 3333 locks(micros) r:10499624 nreturned:5634 reslen:2565182 5684ms

Wed Dec 25 17:27:22.408 [conn31702] query inventory.products_couk query: { sku: "Bel_W_WBRV123SBCHA" } ntoreturn:1 ntoskip:0 nscanned:1 keyUpdates:0 locks(micros) r:250 nreturned:1 reslen:15648 113ms

Wed Dec 25 17:27:22.530 [conn31702] insert inventory.ca_prereprice_result ninserted:1 keyUpdates:0 locks(micros) w:38 120ms

Wed Dec 25 17:27:22.972 [conn31702] insert inventory.ca_prereprice_result ninserted:1 keyUpdates:0 locks(micros) w:96 109ms

Wed Dec 25 17:27:25.647 [conn31664] end connection 127.0.0.1:15390 (55 connections now open)

Wed Dec 25 17:39:21.037 [initandlisten] connection accepted from 127.0.0.1:55049 #31703 (56 connections now open)

Wed Dec 25 17:39:21.068 [initandlisten] connection accepted from 127.0.0.1:55050 #31704 (57 connections now open)

Wed Dec 25 17:47:19.251 [initandlisten] connection accepted from 10.0.0.244:63230 #31705 (58 connections now open)

the process got stuck somewhere after 17:26 as you can see there is a break after 17:27 i think this is it.

my mongo version is 2.4.5

c# driver 1.8

these are not large documents.

i did not use any writeconcern

the mongo db is a service i do not specify any options for its start

one more thing - i restarted the service and then i was able to run the process until the end. maybe it is issue of too much indexing. how can i find out about it?

thanks

[Asya Kamsky]

Here's the problem - mongod doesn't look like it's "to blame" because
it doesn't have anything to do.

If you look at the log:

Wed Dec 25 17:27:25.647 [conn31664] end connection 127.0.0.1:15390 (55
connections now open)

Connection closed...

Wed Dec 25 17:39:21.037 [initandlisten] connection accepted from
127.0.0.1:55049 #31703 (56 connections now open)

New connection opened...

There is no indication that mongod should have been doing any work at
this time. What was your application code doing at this time? I
think you may need to be doing some logging in the app if you are not
already so that you can figure out why and where things pause.

This is not an issue of too much indexing because as you can see,
mongod logs every single operation that takes longer than 100ms. So
it wasn't mongod doing something - at least not looking at the logs
(like I said if it's "stuck" in this mode, start the shell (mongo
command) and run db.currentOp() at the shell prompt to see what
processes are either running or waiting to run.

Asya