Mongo crashing due to increasing connections

[sumit]

Hi All,
We have been trying to deal with this problem for few days now but the
problem seems to persist. I am posting some details here, to get
opinion from the experts. Things like what can we tune in code, what
to monitor, etc. Thanks in advance for your time.

Core problem - we have a mongo instance with approx 200 DBs.
Everything runs fine for 6-7 hours and then the number of connections
start increasing to the allowed limit until the instance becomes
unusable.

Some more details
- Each DB experiences approx 400 reads and updates per second. Each DB
has a single collection approx 80 MB.
- Objects in the DB do not grow or add up i.e. the DB remains constant
in size. Changes are made to a couple of attributes only.
- To separate the reads and writes we tried using a replica set (with
2 servers). When using replica - the slave crashed with similar
problem. At that point thinking something is wrong with our replica
configuration we tried running on a single instance.
- Server is running Ubuntu Server with 16 GB of RAM (dedicated to
Mongo).
- The app uses the Java driver, specifies mongo options of 100
connections, wait queue multiple is 1 and queue timeout is 10. We have
18 such apps....so at the most there should be 1800 connections
hitting Mongo.
- We do not see increase in disk IO when this happens (sometimes the
flushes do pick up but nothing at the time of crash).


Few logs from mongostat. The initial lines show normal operation and
then connections going up, things getting queued, virtual size goes up
until crash...


insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time
0 7 6 0 0 2 0
25228 30356 3776 0 0.2 0 0|0|0 373
22:59:57
0 2 2 0 0 2 0
25228 30356 3776 0 0 0 0|0|0 373
22:59:58
0 1 2 0 0 2 0
25228 30356 3776 0 0 0 0|0|0 373
22:59:59
0 21 9 0 0 2 0
25228 30356 3776 0 0.3 0 0|0|0 373
23:00:00
0 272 239 0 0 2 0
25228 30356 3777 0 6.3 0 99|0|99 373
23:00:01
0 259 230 0 0 2 0
25228 30476 3777 0 8.2 0 175|6|169 386
23:00:02
0 265 244 0 0 2 0
25228 31106 3771 0 8.2 0 260|7|253 449
23:00:03
0 263 204 0 0 1 0
25228 31727 3772 0 6.9 0 329|14|315 513
23:00:04
....................
0 216 1 0 0 2 0
25228 44657 3801 0 0.1 0 1610|328|1282 1805
23:00:17
0 233 1 0 0 2 0
25228 47281 3810 0 0 0 1836|553|1283 2066
23:00:18
....................
0 456 1 0 0 2 0
25228 79975 3962 0 0 0 4406|3117|1289
4973 23:00:32
0 644 2 0 0 2 0
25228 88280 3989 0 0 0 5039|3748|1291
5771 23:00:36
0 794 3 0 0 2 0
25228 99714 4032 0 0 0 5839|4545|1294
6890 23:00:41
0 1188 2 0 0 2 0
25228 117805 4103 0 0 0 6980|5684|1296
8653 23:00:49
0 1663 3 0 0 2 1
25228 143187 4199 0 0 0 7682|6383|1299
11118 23:01:00
0 2557 0 0 0 2 0
25228 147823 4220 0 0 0 11212|9913|1299
11582 23:01:02
0 420 15 0 0 2 0
25228 164535 4324 0 0 0 9377|8062|1315
13107 23:01:20
..............

0 201 0 0 0 3 0
25228 157205 4736 0 0 0 9118|7774|1344
10839 23:52:42
0 1449 0 0 0 2 1
25228 124932 4690 0 0 0 6876|5532|1344
7950 23:52:59
0 0 0 0 0 1 0
25228 110116 4667 0 0 0 7531|6187|1344
7638 23:53:00
0 0 0 0 0 3 0
25228 99102 4650 0 0 0 5785|4441|1344
5930 23:53:10
0 0 0 0 0 4 0
25228 68560 4602 0 0 0 2595|1251|1344
2910 23:53:12
0 541 1 0 0 2 0
25228 41388 4192 0 10.7 0 808|4|804 911
23:53:14
can't get data: DBClientBase::findOne: transport error
Sat Feb 19 23:53:16 trying reconnect to 127.0.0.1
Sat Feb 19 23:53:16 reconnect 127.0.0.1 failed couldn't connect to
server 127.0.0.1
Sat Feb 19 23:53:16 MessagingPort say send() errno:9 Bad file
descriptor 127.0.0.1:27017
can't get data: socket exception

[Gaetan Voyer-Perrault]

Here are some details on the "too many open files" issues:

http://www.mongodb.org/display/DOCS/Too+Many+Open+Files

Please check the ulimit -n value. Each connection needs one file handle, but mongod also needs one file handle for each data file. You have 200 DBs, so that's a minimum of 600 file handles just for the DB.

To monitor the number of connections, you can track 

db.serverStatus().connections.current and

db.serverStatus().connections.available

Normally, you should see connections rise when you start mongod. Then the connections should "top out" and hold at that position. In your case, it looks like connections shut up to 13k and then dropped off suddenly.

A couple of questions to hopefully point us in the right direction:

 - Do you have servers coming on-line and off-line during that period?

 - What iostat look like during that period? Do you have enough disk throughput for the writes?

 - What versions are you using (java driver and mongo)?

 - Gates

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

[sumit]

Thanks Gates.
Here are responses and few follow up questions. Any help/insights to
troubleshoot this problem more is greatly appreciated. Thanks again.

- We are using mongo 1.6.5 and java driver 2.4
- The server is dedicated to mongo and we do not see a lot of IO
activity. So there should be enough throughput.
- We raised the number of file descriptors i.e. ulimit to allow 13K
connections.
- Number of machines/clients remain the same, we didnt have machines
going up and down.

Some follow up questions
- How did you determine the 600 open connections for 200 DBs. (does it
need 3 per db, how do we determine that multiple)
- We were tracking the number of connections via mongostat. Is it not
the best and should we use db.serverStatus().connections.current and
db.serverStatus().connections.available
- When the server starts we see the number of connections 'top out' at
around 400-500. Everything works fine for few hours and then the
number of connections start going up until the 13K limit is reached
and it stops responding. Not

Sumit

On Feb 21, 4:57 pm, Gaetan Voyer-Perrault <ga...@10gen.com> wrote:
> Here are some details on the "too many open files" issues:http://www.mongodb.org/display/DOCS/Too+Many+Open+Files
>
> <http://www.mongodb.org/display/DOCS/Too+Many+Open+Files>
> Please check the ulimit -n value. Each connection needs one file handle, but
> mongod also needs one file handle for each data file. You have 200 DBs, so
> that's a minimum of 600 file handles just for the DB.
>
> To monitor the number of connections, you can track
> db.serverStatus().connections.current and
> db.serverStatus().connections.available
>
> Normally, you should see connections rise when you start mongod. Then the
> connections should "top out" and hold at that position. In your case, it
> looks like connections shut up to 13k and then dropped off suddenly.
>
> A couple of questions to hopefully point us in the right direction:
>  - Do you have servers coming on-line and off-line during that period?
>  - What iostat look like during that period? Do you have enough disk
> throughput for the writes?
>  - What versions are you using (java driver and mongo)?
>
>  - Gates
>

[Eliot Horowitz]

Can you try master of the java driver.
There was an edge case where its possible to leak connections.

[wue]

Eliot, thanks for the reply. We will try this shortly. If it is not
too complicated, can you explain the edge case?

Thanks, Markus

> ...
>
> read more »

[Kaustubh Padegaonkar]

Hi,

I had a single DB, but had the same problem, we had to change our code. We created a single connection, per JVM. Now my connections never rise beyond 50. Earlier they used to go till 700. My config is the same, as yours, mongo v1.6.5, with java driver 2.4. 

Again, I havent upped the ulimit, mainly because we have a single database, and aren't very DB intensive.

Regards,

Kaustubh Padegaonkar.

[stone]

We encountered the similar problem before, we use Resque worker to
process the jobs. Resque use fork model, so it creates many short
lived connections per seconds. When we run more than 10 workers, every
a few minutes mongod stops respond. Finally we by-passed the problem
by hack Resque to not forking.

I the log is like the following (notice the all zero lines):



0 1616 1114 0 0 781 0 53383
54080 2829 11 26.7 0 0|0|0 27 23:03:49
0 1241 868 0 0 616 0
53383 54024 2829 4 21.3 0 0|0|0 17
23:03:50
0 0 0 0 1 2 0
53383 54024 2829 0 0 0 0|0|0 17
23:03:51
0 0 0 0 0 2 0
53383 54024 2829 0 0 0 0|0|0 17
23:03:52
0 0 0 0 0 2 0
53383 54024 2829 0 0 0 0|0|0 17
23:03:53
0 1146 777 0 0 574 0
53383 54088 2830 5 19.4 0 1|1|0 28
23:03:54
0 1650 1170 0 0 827 0
53383 54080 2830 9 27.9 0 0|0|0 26
23:03:55
0 1599 1101 0 0 755 0
53383 54096 2831 8 28 0 0|0|0 26
23:03:56
1 1487 1051 0 1 721 0
53383 54056 2831 8 25 0 0|0|0 21
23:03:57
0 1630 1115 0 0 772 0
53383 54096 2832 2 26 0 0|0|0 27
23:03:58
0 1540 1152 0 0 748 0
53383 54120 2832 10 28.3 0 0|0|0 30
23:03:59
0 1660 1219 0 0 789 0
53383 54096 2833 6 31.5 0 0|0|0 29
23:04:00
2 1657 1203 0 0 805 0
53383 54104 2834 10 27.7 0 1|0|1 29
23:04:01
0 1642 1090 0 0 778 0
53383 54096 2834 9 26.1 0 0|0|0 30
23:04:02
3 1738 1172 0 0 825 0
53383 54104 2835 9 29.9 0 0|0|0 28
23:04:03
2 1733 1148 0 0 858 0
53383 54112 2836 10 27.4 0 0|0|0 30
23:04:04
1 1796 1206 0 0 876 0
53383 54112 2836 11 30.1 0 0|0|0 30
23:04:05

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1663 1151 0 1 797 0
53383 54112 2837 2 27.5 0 0|0|0 29
23:04:06
0 406 318 0 0 224 0
53383 54032 2837 1 7.3 0 0|0|0 18
23:04:07

0 0 0 0 0 3 0

53383 54032 2837 0 0 0 0|0|0 18
23:04:08
1 1332 858 0 0 623 0
53383 54104 2838 6 21.3 0 0|0|0 30
23:04:09
1 1934 1328 0 0 954 0
53383 54080 2838 8 31.7 0 0|0|0 27
23:04:10
2 1943 1363 0 0 945 0
53383 54104 2839 8 34.1 0 0|0|0 28
23:04:11
2 1871 1264 0 0 896 0
53383 54096 2840 6 30.4 0 0|0|0 26
23:04:12
1 1745 1155 0 1 823 0
53383 54112 2840 8 26.9 0 0|0|0 29
23:04:13
0 1606 1179 0 0 788 0
53383 54112 2841 9 27.8 0 0|0|0 31
23:04:14
2 1405 1024 0 0 685 0
53383 54112 2842 4 24.4 0 0|0|0 28
23:04:15
1 1392 969 0 0 664 0
53383 54104 2842 9 23.9 0 3|0|3 28
23:04:16
0 1422 974 0 0 675 0
53383 54072 2843 4 23.3 0 0|0|0 23
23:04:17
0 1517 996 0 0 718 0
53383 54088 2843 11 25.1 0 0|0|0 28
23:04:18
0 1743 1175 0 0 844 0
53383 54080 2844 7 28.2 0 0|0|0 25
23:04:19
0 72 60 0 0 34 0
53383 54032 2844 0 1.4 0 0|0|0 18
23:04:20
0 0 0 0 1 3 0
53383 54032 2844 0 0 0 0|0|0 18
23:04:21
0 0 0 0 0 2 0
53383 54032 2844 0 0 0 0|0|0 18
23:04:22

0 0 0 0 0 1 0

53383 54032 2844 0 0 0 0|0|0 18
23:04:23
0 1336 907 0 0 636 0
53383 54088 2844 10 22.1 0 0|0|0 27
23:04:24
0 1572 1062 0 0 758 0
53383 54080 2845 16 36.6 0 0|0|0 26
23:04:25

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1882 1330 0 0 910 0
53383 54112 2846 10 32 0 0|0|0 28
23:04:26
0 1889 1305 0 0 905 0
53383 54096 2847 13 31.7 0 1|1|0 28
23:04:27
0 1798 1263 0 1 880 0
53383 54112 2847 9 30.3 0 1|0|1 30
23:04:28
0 1780 1204 0 0 848 0
53383 54104 2848 10 29.6 0 0|0|0 30
23:04:29
0 1560 1065 0 0 748 0
53383 54104 2849 7 25.4 0 0|0|0 30
23:04:30
0 1521 1050 0 0 737 0
53383 54112 2849 5 25.8 0 0|0|0 30
23:04:31
2 1333 929 0 0 662 0
53383 54104 2850 10 23.1 0 0|0|0 27
23:04:32
0 1400 944 0 0 669 0
53383 54080 2850 8 22.9 0 1|1|0 27
23:04:33
0 1742 1186 0 0 819 0
53383 54104 2851 7 28.2 0 1|1|0 29
23:04:34
0 1781 1172 0 0 844 0
53383 54080 2851 7 28.3 0 0|0|0 24
23:04:35
0 376 257 0 0 184 0
53383 54032 2851 0 6.1 0 0|0|0 18
23:04:36
0 0 0 0 1 2 0
53383 54032 2851 0 0 0 0|0|0 18
23:04:37
0 0 0 0 0 2 0
53383 54032 2851 0 0 0 0|0|0 18
23:04:38
0 1332 876 0 0 633 0
53383 54088 2852 8 20.8 0 0|0|0 27
23:04:39
0 1852 1269 0 0 903 0
53383 54104 2853 9 30.5 0 0|0|0 27
23:04:40
1 1824 1201 0 0 858 0
53383 54104 2853 10 30.5 0 1|0|1 31
23:04:41
0 1902 1295 0 0 910 0
53383 54104 2854 6 31.7 0 0|0|0 30
23:04:42
1 1866 1257 0 0 887 0
53383 54080 2855 11 32.1 0 0|0|0 26
23:04:43
0 1828 1181 0 1 853 0
53383 54088 2855 5 28.5 0 0|0|0 26
23:04:44
0 1710 1169 0 0 823 0
53383 54096 2856 5 28.3 0 0|0|0 29
23:04:45

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1565 1064 0 0 740 0
53383 54112 2857 7 25.3 0 9|4|5 32
23:04:46
0 842 578 0 0 425 1
53383 54096 2857 4 47.8 0 0|0|0 27
23:04:47
0 1437 978 0 0 689 0
53383 54120 2858 4 23.6 0 0|0|0 31
23:04:48
1 1383 982 0 0 661 0
53383 54088 2858 5 24.5 0 0|0|0 25
23:04:49
0 626 491 0 0 313 0
53383 54032 2858 3 11.6 0 0|0|0 18
23:04:50
0 0 0 0 1 2 0
53383 54032 2858 0 0 0 0|0|0 18
23:04:51
0 0 0 0 0 2 0
53383 54032 2858 0 0 0 0|0|0 18
23:04:52
0 0 0 0 0 2 0
53383 54032 2858 0 0 0 0|0|0 18
23:04:53
1 1371 734 0 0 630 0
53383 54096 2860 34 19 0 2|1|1 28
23:04:54
3 2301 1403 0 0 1208 0
53383 54104 2862 35 29.7 0 2|1|1 31
23:04:55
1 1995 1164 0 0 975 0
53383 54080 2863 22 25.6 0 0|0|0 26
23:04:56
0 2326 1376 0 1 1190 0
53383 54104 2864 21 28.3 0 0|0|0 28
23:04:57
3 2185 1475 0 0 1147 0
53383 54120 2867 36 30.4 0 12|1|11 32
23:04:58
3 1905 1241 0 0 944 0
53383 54096 2869 43 29.5 0 5|4|1 29
23:04:59
0 1948 1203 0 0 929 0
53383 54112 2874 46 27 0 8|3|5 31
23:05:00
0 1946 1071 0 0 929 0
53383 54104 2875 27 23.7 0 0|0|0 28
23:05:01
0 1600 794 0 0 734 0
53383 54072 2876 3 16.5 0 0|0|0 26
23:05:02
0 1316 666 0 0 609 0
53383 54088 2877 10 14.2 0 0|0|0 29
23:05:03
0 1401 710 0 1 645 0
53383 54088 2878 14 14.8 0 0|0|0 26
23:05:04
0 1545 815 0 0 727 0
53383 54088 2880 14 17.5 0 0|0|0 27
23:05:05

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 282 152 0 0 139 0
53383 54032 2880 7 3.2 0 0|0|0 18
23:05:06
0 0 0 0 0 2 0
53383 54032 2880 0 0 0 0|0|0 18
23:05:07
0 0 0 0 0 2 0
53383 54032 2880 0 0 0 0|0|0 18
23:05:08
0 1518 787 0 0 706 0
53383 54088 2881 20 16.3 0 0|0|0 26
23:05:09
0 1868 963 0 0 864 0
53383 54096 2883 20 20.5 0.9 10|4|6 31
23:05:11
0 1855 958 0 0 864 0
53383 54088 2885 22 19.6 0 0|0|0 26
23:05:12
0 1771 906 0 0 813 0
53383 54088 2886 30 19.2 0 0|0|0 29
23:05:13
0 1802 935 0 1 850 0
53383 54032 2888 29 20.3 0 0|0|0 18
23:05:14
0 1872 967 0 0 867 0
53383 54088 2890 30 20.4 0 0|0|0 25
23:05:15
0 1769 900 0 0 814 0
53383 54112 2891 39 19.9 0 0|0|0 30
23:05:16
0 1598 863 0 0 741 0
53383 54104 2893 28 18.3 0 0|0|0 28
23:05:17
0 1414 746 0 0 673 0
53383 54064 2894 22 17 0 0|0|0 23
23:05:18
0 1371 704 0 0 636 0
53383 54096 2895 23 15 0 0|0|0 29
23:05:19
0 422 227 0 0 204 0
53383 54032 2895 6 5.2 0 0|0|0 18
23:05:20
0 0 0 0 1 2 0
53383 54032 2895 0 0 0 0|0|0 18
23:05:21
0 0 0 0 0 2 0
53383 54032 2895 0 0 0 0|0|0 18
23:05:22

0 0 0 0 0 1 0

53383 54032 2895 0 0 0 0|0|0 18
23:05:23

0 0 0 0 0 3 0

53383 54032 2895 0 0 0 0|0|0 18
23:05:24
0 1473 767 0 0 682 0
53383 54096 2896 27 17 0 0|0|0 26
23:05:25
0 1605 836 0 0 748 0
53383 54088 2898 42 17.6 0 0|0|0 25
23:05:26

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1887 976 0 0 876 0
53383 54112 2900 31 21.5 0 0|0|0 30
23:05:27
0 1870 976 0 0 865 0
53383 54088 2901 30 22 0 0|0|0 29
23:05:28
0 1809 966 0 0 857 0
53383 54096 2903 24 24.6 0 0|0|0 27
23:05:29
0 1602 836 0 1 753 0
53383 54104 2904 21 17.8 0 0|0|0 30
23:05:30
0 1561 843 0 0 755 0
53383 54072 2905 20 18.2 0 0|0|0 27
23:05:31
0 1493 870 0 0 677 0
53383 54096 2906 3 20.3 0 0|0|0 30
23:05:32
0 1481 880 0 0 667 0
53383 54088 2906 0 20.9 0 0|0|0 26
23:05:33
0 1477 865 0 0 668 0
53383 54080 2906 0 20.5 0 0|0|0 28
23:05:34
1 1160 719 0 0 532 0
53383 54032 2907 2 17.5 0 0|0|0 18
23:05:35
0 0 0 0 0 2 0
53383 54032 2907 0 0 0 0|0|0 18
23:05:36
0 0 0 0 1 2 0
53383 54032 2907 0 0 0 0|0|0 18
23:05:37
0 0 0 0 0 2 0
53383 54032 2907 0 0 0 0|0|0 18
23:05:38
0 0 0 0 0 2 0
53383 54032 2907 0 0 0 0|0|0 18
23:05:39
0 1701 882 0 0 778 0
53383 54096 2908 12 18.4 0 0|0|0 29
23:05:40
0 2051 1074 0 0 950 0
53383 54104 2909 4 22.6 0 0|0|0 29
23:05:41
0 1898 979 0 0 882 0
53383 54088 2910 8 20.9 0 5|3|2 27
23:05:42
0 1681 911 0 1 796 0
53383 54048 2910 6 21 0 0|0|0 20
23:05:43
0 1562 808 0 0 712 0
53383 54104 2912 17 16.9 1.1 0|0|0 30
23:05:44
0 1459 757 0 0 675 0
53383 54096 2912 3 15.8 0 0|0|0 29
23:05:45
0 1400 727 0 0 646 0
53383 54080 2913 1 15.8 0 0|0|0 27
23:05:46

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1577 802 0 0 719 1
53383 54096 2914 2 16.8 0 0|0|0 27
23:05:47
0 899 479 0 0 421 0
53383 54032 2914 3 10.4 0 0|0|0 18
23:05:48
0 0 0 0 0 2 0
53383 54032 2914 0 0 0 0|0|0 18
23:05:49
0 0 0 0 1 3 0
53383 54032 2914 0 0 0 0|0|0 18
23:05:50
0 0 0 0 0 2 0
53383 54032 2914 0 0 0 0|0|0 18
23:05:51
0 0 0 0 0 2 0
53383 54032 2914 0 0 0 0|0|0 18
23:05:52
0 0 0 0 0 2 0
53383 54032 2914 0 0 0 0|0|0 18
23:05:53
0 0 0 0 0 2 0
53383 54032 2914 0 0 0 0|0|0 18
23:05:54
0 1677 978 0 0 756 0
53383 54096 2915 1 23.1 0 1|0|1 30
23:05:55
1 1895 1100 0 0 854 0
53383 54088 2915 3 25.7 0 0|0|0 28
23:05:56
0 1688 1002 0 0 764 0
53383 54096 2916 2 23.9 0 0|0|0 28
23:05:57
0 1438 850 0 1 654 0
53383 54088 2916 2 20.6 0 0|0|0 25
23:05:58
0 1573 902 0 0 702 0
53383 54080 2916 3 21.8 0 2|0|2 26
23:05:59
0 1517 866 0 0 677 0
53383 54104 2917 1 20.5 0 0|0|0 28
23:06:00
0 1513 899 0 0 683 0
53383 54072 2917 0 21.1 0 0|0|0 24
23:06:01
0 1558 903 0 0 697 0
53383 54072 2918 3 21.3 0 0|0|0 26
23:06:02
0 1722 990 0 0 785 0
53383 54080 2918 5 22.7 0 9|7|2 28
23:06:03
1 1844 1060 0 1 818 0
53383 54104 2919 4 35.6 0 2|1|1 30
23:06:04
0 2027 1179 0 0 913 0
53383 54080 2919 0 27.8 0 0|0|0 25
23:06:05
0 272 163 0 0 128 0
53383 54024 2919 0 3.8 0 0|0|0 17
23:06:06

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 0 0 0 0 2 0
53383 54024 2919 0 0 0 0|0|0 17
23:06:07

0 0 0 0 0 3 0

53383 54024 2919 0 0 0 0|0|0 17
23:06:08
0 0 0 0 0 2 0
53383 54024 2919 0 0 0 0|0|0 17
23:06:09
0 1610 823 0 0 745 0
53383 54080 2920 10 16.9 0 0|0|0 27
23:06:10
0 1440 746 0 1 669 0
53383 54088 2922 11 15.5 0 1|0|1 27
23:06:11
0 1464 763 0 0 680 0
53383 54064 2923 14 16.8 0 0|0|0 26
23:06:12
0 1407 813 0 0 665 0
53383 54104 2923 4 17.6 0 0|0|0 28
23:06:13
0 1388 779 0 0 651 0
53383 54064 2924 6 16.3 0 1|0|1 25
23:06:14
0 1593 854 0 0 749 0
53383 54072 2924 6 17.8 0 0|0|0 27
23:06:15
0 1762 971 0 0 827 0
53383 54056 2925 5 20.8 0 0|0|0 25
23:06:16
0 1862 1026 0 0 866 0
53383 54080 2925 6 21.2 0 0|0|0 25
23:06:17
1 2000 1063 0 0 932 0
53383 54056 2926 6 21.6 0 0|0|0 21
23:06:18
0 1271 751 0 0 606 0
53383 54024 2926 3 15.6 0 0|0|0 17
23:06:19
0 0 0 0 1 2 0
53383 54024 2926 0 0 0 0|0|0 17
23:06:20
0 0 0 0 0 2 0
53383 54024 2926 0 0 0 0|0|0 17
23:06:21
0 0 0 0 0 2 0
53383 54024 2926 0 0 0 0|0|0 17
23:06:22
0 0 0 0 0 2 0
53383 54024 2926 0 0 0 0|0|0 17
23:06:23
0 0 0 0 0 2 0
53383 54024 2926 0 0 0 0|0|0 17
23:06:24
0 1663 903 0 0 785 0
53383 54088 2927 7 19.7 0 0|0|0 26
23:06:25
0 1572 850 0 1 728 0
53383 54056 2928 4 17.4 0 0|0|0 21
23:06:26

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

1 1424 743 0 0 676 0
53383 54096 2928 5 15.7 0 0|0|0 26
23:06:27
0 1518 858 0 0 736 0
53383 54048 2929 6 18.6 0 0|0|0 22
23:06:28
0 1752 917 0 0 826 0
53383 54080 2929 4 19.1 0 0|0|0 27
23:06:29
0 1898 1041 0 0 900 0
53383 54080 2930 9 22.1 0 1|0|1 26
23:06:30
0 1865 1003 0 0 883 0
53383 54064 2931 8 20.5 0 0|0|0 22
23:06:31
0 1789 959 0 0 848 0
53383 54080 2931 5 20.3 0 6|3|3 26
23:06:32
1 1663 920 0 1 799 0
53383 54080 2932 4 19.3 0 0|0|0 27
23:06:33
0 1719 907 0 0 802 0
53383 54088 2932 4 18.7 0 0|0|0 27
23:06:34
0 1549 845 0 0 752 0
53383 54024 2933 4 17.5 0 0|0|0 17
23:06:35
0 0 0 0 0 2 0
53383 54024 2933 0 0 0 0|0|0 17
23:06:36
0 0 0 0 0 2 0
53383 54024 2933 0 0 0 0|0|0 17
23:06:37
0 0 0 0 1 3 0
53383 54024 2933 0 0 0 0|0|0 17
23:06:38
0 0 0 0 0 2 0
53383 54016 2933 0 0 0 0|0|0 16
23:06:39
0 1436 764 0 0 679 0
53383 54072 2933 4 16.4 0 0|0|0 24
23:06:40
0 1499 794 0 0 702 0
53383 54056 2934 4 16.2 0 0|0|0 23
23:06:41
0 1642 886 0 0 780 0
53383 54072 2934 7 18.1 0 1|0|1 25
23:06:42
0 1742 951 0 0 823 0
53383 54072 2935 5 19.6 0 0|0|0 23
23:06:43
0 1570 845 0 1 744 0
53383 54032 2936 2 17.4 0 0|0|0 18
23:06:44
0 1537 845 0 0 723 0
53383 54064 2936 3 17.8 0 0|0|0 23
23:06:45
0 1630 910 0 0 767 0
53383 54064 2936 2 18.7 0 0|0|0 25
23:06:46

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1620 895 0 0 758 0
53383 54072 2937 4 18.6 0 0|0|0 25
23:06:47
0 1218 677 0 0 577 1
53383 54064 2937 4 17.7 0 0|0|0 24
23:06:48
0 1470 786 0 0 687 0
53383 54056 2937 0 16.8 0 0|0|0 24
23:06:49
0 103 67 0 0 56 0
53383 54016 2937 0 1.4 0 0|0|0 16
23:06:50
0 0 0 0 0 2 0
53383 54016 2937 0 0 0 0|0|0 16
23:06:51
0 0 0 0 1 2 0
53383 54016 2937 0 0 0 0|0|0 16
23:06:52
0 0 0 0 0 2 0
53383 54016 2937 0 0 0 0|0|0 16
23:06:53
0 0 0 0 0 2 0
53383 54016 2937 0 0 0 0|0|0 16
23:06:54
0 1677 1125 0 0 805 0
53383 54072 2938 6 25.8 0 0|0|0 24
23:06:55
0 1673 1173 0 0 818 0
53383 54088 2939 9 27 0 0|0|0 28
23:06:56
1 1424 1029 0 0 707 0
53383 54080 2939 5 23.7 0 0|0|0 26
23:06:57
0 1448 993 0 1 707 0
53383 54080 2940 5 23.1 0 0|0|0 26
23:06:58
0 1477 1007 0 0 716 0
53383 54088 2940 4 24 0 1|1|0 28
23:06:59
1 1477 1037 0 0 725 0
53383 54072 2941 5 23.8 0 0|0|0 24
23:07:00
0 1765 1018 0 0 834 0
53383 54072 2941 1 21 0 0|0|0 27
23:07:01
0 1581 849 0 0 739 0
53383 54040 2942 4 18 0 0|0|0 23
23:07:02
0 1514 817 0 0 715 0
53383 54072 2942 3 16.6 0 0|0|0 24
23:07:03
0 1369 743 0 0 644 0
53383 54072 2942 5 21.2 0 0|0|0 24
23:07:04
0 1421 790 0 1 683 0
53383 54072 2943 2 16.1 0 0|0|0 26
23:07:05
0 1697 921 0 0 792 0
53383 54064 2943 1 18.4 0 0|0|0 24
23:07:06

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1510 828 0 0 715 0
53383 54072 2944 4 18 0 0|0|0 23
23:07:07
0 1298 721 0 0 615 0
53383 54064 2944 4 15.9 0 0|0|0 23
23:07:08
0 1303 730 0 0 621 0
53383 54016 2944 2 14.9 0 0|0|0 17
23:07:09
1 1683 879 0 1 783 0
53383 54072 2945 3 17.4 0 1|0|1 26
23:07:10
0 1853 1014 0 0 855 0
53383 54072 2946 2 21.1 0 2|2|0 27
23:07:11
0 1626 916 0 0 766 0
53383 54064 2946 2 18.9 0 0|0|0 26
23:07:12
0 1614 866 0 0 759 0
53383 54064 2946 1 17.6 0 0|0|0 25
23:07:13
0 1791 972 0 0 838 0
53383 54072 2947 6 19.6 0 0|0|0 25
23:07:14
0 1781 978 0 0 835 0
53383 54072 2947 3 19.7 0 2|1|1 25
23:07:15
0 1655 867 0 1 766 0
53383 54072 2948 6 18 0 0|0|0 26
23:07:16
1 1388 758 0 0 658 0
53383 54080 2948 3 15.5 0 0|0|0 24
23:07:17
0 1460 771 0 0 683 0
53383 54072 2949 3 15.6 0 0|0|0 24
23:07:18
0 1497 785 0 0 699 0
53383 54064 2949 5 16.1 0 0|0|0 23
23:07:19
0 1058 571 0 0 503 0
53383 54016 2949 5 11.4 0 0|0|0 16
23:07:20
0 0 0 0 0 2 0
53383 54016 2949 0 0 0 0|0|0 16
23:07:21
0 0 0 0 0 2 0
53383 54016 2949 0 0 0 0|0|0 16
23:07:22
0 0 0 0 1 3 0
53383 54016 2949 0 0 0 0|0|0 16
23:07:23
0 9 0 0 0 5 0
53383 54016 2949 0 0 0 0|0|0 19
23:07:24
0 1808 1009 0 0 851 0
53383 54064 2950 2 20.9 0 0|0|0 24
23:07:25
1 1921 1047 0 0 901 0
53383 54064 2950 1 20.9 0 0|0|0 25
23:07:26

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

1 1569 889 0 0 743 0
53383 54056 2951 1 31.9 0 0|0|0 21
23:07:27
0 1646 875 0 1 764 0
53383 54064 2951 4 17.9 0 0|0|0 24
23:07:28
1 1632 909 0 0 776 0
53383 54056 2952 4 18.8 0 0|0|0 22
23:07:29
1 1542 836 0 0 726 0
53383 54088 2952 0 17 0 1|0|1 27
23:07:30
0 1389 749 0 0 656 0
53383 54072 2952 6 15.5 0 0|0|0 23
23:07:31
0 1492 789 0 0 695 0
53383 54072 2953 1 16 0 0|0|0 23
23:07:32
0 1011 560 0 0 477 0
53383 54080 2953 3 12.2 0 0|0|0 27
23:07:33
0 1292 730 0 1 621 0
53383 54048 2954 2 15 0 0|0|0 20
23:07:34
0 1548 831 0 0 730 0
53383 54048 2954 1 16.8 0 0|0|0 23
23:07:35
2 1464 773 0 0 679 0
53383 54016 2954 1 16.3 0 0|0|0 16
23:07:36
0 0 0 0 0 3 0
53383 54016 2954 0 0 0 0|0|0 16
23:07:37
0 0 0 0 0 2 0
53383 54016 2954 0 0 0 0|0|0 16
23:07:38
0 71 23 0 0 25 0
53383 54096 2954 0 0.4 0 0|0|0 26
23:07:39
0 1758 981 0 0 833 0
53383 54056 2955 0 20 0 1|0|1 25
23:07:40
0 1788 955 0 1 843 0
53383 54064 2955 0 18.9 0 0|0|0 23
23:07:41
1 1738 930 0 0 814 0
53383 54056 2955 0 18.7 0 0|0|0 22
23:07:42
0 1592 857 0 0 738 0
53383 54072 2955 0 17.2 0 0|0|0 26
23:07:43
1 1454 794 0 0 676 0
53383 54064 2955 0 16.1 0 0|0|0 24
23:07:44
0 1458 808 0 0 693 0
53383 54056 2955 0 16.6 0 0|0|0 24
23:07:45
0 1382 757 0 0 648 0
53383 54064 2955 0 15.4 0 1|0|1 25
23:07:46

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1363 735 0 0 646 1
53383 54064 2955 0 15.6 0 0|0|0 25
23:07:47
0 1233 688 0 1 583 0
53383 54016 2955 1 13.9 0 0|0|0 16
23:07:48
0 0 0 0 0 2 0
53383 54016 2955 0 0 0 0|0|0 16
23:07:49
0 0 0 0 0 2 0
53383 54016 2955 0 0 0 0|0|0 16
23:07:50
0 0 0 0 0 2 0
53383 54016 2955 0 0 0 0|0|0 16
23:07:51
0 0 0 0 0 2 0
53383 54016 2955 0 0 0 0|0|0 16
23:07:52
0 0 0 0 0 2 0
53383 54016 2955 0 0 0 0|0|0 16
23:07:53
0 93 44 0 1 40 0
53383 54072 2956 0 0.9 0 0|0|0 25
23:07:54
0 1606 937 0 0 779 0
53383 54064 2956 0 19.5 0 0|0|0 24
23:07:55
0 1560 922 0 0 749 0
53383 54064 2956 0 19.3 0 0|0|0 23
23:07:56
0 1024 580 0 0 489 0
53383 54064 2956 0 11.6 0 0|0|0 24
23:07:57
0 1230 711 0 1 593 0
53383 54056 2956 0 14.1 0 0|0|0 21
23:07:58
0 1301 727 0 0 618 0
53383 54064 2956 0 14.7 0 0|0|0 24
23:07:59
0 1111 615 0 0 526 0
53383 54064 2956 0 12.8 0 0|0|0 25
23:08:00
0 1162 702 0 0 558 0
53383 54040 2957 0 14.6 0 0|0|0 22
23:08:01
0 1319 764 0 0 640 0
53383 54040 2957 1 15.4 0 0|0|0 20
23:08:02
0 1419 786 0 0 672 0
53383 54040 2957 0 15.8 0 1|1|0 22
23:08:03
0 1464 843 0 0 699 0
53383 54048 2957 0 17.1 0 0|0|0 23
23:08:04
0 1482 832 0 1 701 0
53383 54032 2957 0 16.5 0 0|0|0 22
23:08:05
0 1520 836 0 0 719 0
53383 54048 2957 0 16.7 0 0|0|0 20
23:08:06

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1519 827 0 0 713 0
53383 54048 2957 0 16.4 0 0|0|0 22
23:08:07
0 1047 581 0 0 503 0
53383 54008 2957 0 11.3 0 0|0|0 15
23:08:08
0 86 41 0 0 41 0
53383 54048 2957 0 0.8 0 0|0|0 23
23:08:09
0 1306 771 0 1 635 0
53383 54040 2957 0 15 0 0|0|0 21
23:08:10
0 1423 796 0 0 672 0
53383 54048 2958 0 15.8 0 0|0|0 22
23:08:11
0 1371 773 0 0 650 0
53383 54048 2958 0 15.2 0 0|0|0 21
23:08:12
0 1213 680 0 0 567 0
53383 54048 2958 0 13.5 0 0|0|0 22
23:08:13
0 1211 699 0 0 588 0
53383 54056 2958 0 13.8 0 0|0|0 23
23:08:14
0 1023 600 0 0 493 0
53383 54056 2958 0 12.1 0 0|0|0 22
23:08:15
0 1197 631 0 1 547 0
53383 54048 2958 0 12.6 0 2|1|1 24
23:08:16
0 1450 849 0 0 698 0
53383 54048 2959 1 17 0 0|0|0 22
23:08:17
0 1503 901 0 0 732 0
53383 54048 2959 0 17.9 0 0|0|0 20
23:08:18
0 1519 856 0 0 720 0
53383 54048 2959 0 17 0 0|0|0 20
23:08:19
0 1391 796 0 0 657 0
53383 54040 2959 0 16.1 0 0|0|0 21
23:08:20
1 1433 777 0 0 676 0
53383 54048 2959 0 15.2 0 0|0|0 23
23:08:21
0 979 564 0 0 474 0
53383 54008 2959 0 11.1 0 0|0|0 15
23:08:22
0 0 0 0 1 2 0
53383 54008 2959 0 0 0 0|0|0 15
23:08:23
0 101 51 0 0 44 0
53383 54056 2959 0 0.9 0 0|0|0 25
23:08:24
0 1484 815 0 0 694 0
53383 54056 2959 1 16.2 0 0|0|0 22
23:08:25
0 1374 764 0 0 652 0
53383 54048 2959 0 15.1 1.2 0|0|0 20
23:08:26

insert/s query/s update/s delete/s getmore/s command/s flushes/s
mapped vsize res faults/s locked % idx miss % q t|r|w
conn time

0 1256 690 0 0 595 0
53383 54056 2960 0 13.6 0 0|0|0 21
23:08:27
0 1050 592 0 1 496 0
53383 54048 2960 0 12.2 0 0|0|0 22
23:08:28
0 1130 629 0 0 530 0
53383 54040 2960 0 12.4 0 1|0|1 23
23:08:29
0 1430 799 0 0 680 0
53383 54048 2960 0 15.8 0 0|0|0 20
23:08:30
0 1626 904 0 0 767 0
53383 54048 2960 0 17.3 0 0|0|0 23
23:08:31
0 1623 910 0 0 765 0
53383 54048 2960 0 17.9 0 0|0|0 21
23:08:32
0 1521 866 0 0 720 0
53383 54064 2960 0 16.7 0 0|0|0 22
23:08:33
0 1311 737 0 0 629 0
53383 54040 2960 0 14.6 0 0|0|0 22
23:08:34
0 1303 705 0 0 586 0
53383 54056 2961 0 14 0 0|0|0 23
23:08:35
1 1161 659 0 0 550 0
53383 54040 2961 0 12.2 0 0|0|0 20
23:08:36
0 1360 761 0 1 645 0
53383 54040 2962 0 14 0 0|0|0 21
23:08:37
0 533 317 0 0 265 0
53383 54008 2961 0 6.3 0 0|0|0 15
23:08:38
0 98 48 0 0 43 0
53383 54032 2961 0 0.9 0 0|0|0 20
23:08:39
0 1370 760 0 0 645 0
53383 54048 2961 0 15 0 0|0|0 23
23:08:40
0 1178 642 0 0 557 0
53383 54056 2961 0 12.7 0 0|0|0 24
23:08:41
0 1080 600 0 1 513 0
53383 54048 2961 0 11.8 0 0|0|0 22
23:08:42
0 1253 688 0 0 586 0
53383 54040 2961 0 13.7 0 0|0|0 23
23:08:43
1 1565 859 0 1 738 0
53383 54056 2961 0 17.3 0 0|0|0 23
23:08:44

[sumit]

Thanks Kaustubh and Stone.

From your experiences it looks like you were able to stop increasing
connection problem by limiting connections to 1 (or few). Thanks a lot
for sharing we will try it. In one of our other app we were using 5
connections and we constantly ran into 'not enough semaphore
available' errors from Mongo.

Any case we will try your approach and the new jar suggestion from
Elliot. I will post our findings here.

sumit

> ...
>
> read more »

[wue]

Hi,
we tried to use the latest driver and immediately got lots of these
error messages:
cannot find: class com.mongodb.CommandResult$CommandFailure, null,
command failed [command failed [findandmodify] { "errmsg" : "No
matching object found" , "ok" : 0.0}

I couldn't find any information on it. Anybody know what the problem
is?

Thanks,
Markus

> ...
>
> read more »