Very strange number of connections to secondary server

[Oleg Lobach]

Hi all

We use a replica set of the scheme the master/slave/arbiter.
Today we noticed a very strange number of connections: 15 670 active
and 330 free (serverStatus show this). But our application communicate
with master only. And very small number of TCP connects we see
(netstat -ant | grep ESTABLISHED command show ~10 connections).

What kind of connection, and why so many?

[Nat]

Can you attach some part of the log files, db.currentOp(), netstat?

[Scott Hernandez]

What state are the rest in? It could be that the network/firewall is
closing connections on you.

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

[Oleg Lobach]

> Can you attach some part of the log files, db.currentOp(), netstat?

Here is db.currentOp() output:

iii-prod:SECONDARY> db.currentOp();
{
"inprog" : [
{
"opid" : 651777180,
"active" : false,
"waitingForLock" : false,
"op" : "none",
"ns" : "?ii_stuff.inf_bot_ex",
"query" : {

},
"client" : "(NONE)",
"desc" : "replica set sync"
}
]
}

Here is netstat output:

# netstat -ant
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address
State
tcp 0 0 81.95.XXX.YYY:10050 0.0.0.0:*
LISTEN
tcp 0 0 192.168.1.21:27017 0.0.0.0:*
LISTEN
tcp 0 0 192.168.1.21:28017 0.0.0.0:*
LISTEN
tcp 0 0 0.0.0.0:22 0.0.0.0:*
LISTEN
tcp 0 0 127.0.0.1:6010 0.0.0.0:*
LISTEN
tcp 0 0 192.168.1.21:27017 192.168.1.17:24927
ESTABLISHED
tcp 0 0 192.168.1.21:55433 192.168.1.21:27017
TIME_WAIT
tcp 0 0 81.95.XXX.YYY:43124 192.168.1.14:27017
ESTABLISHED
tcp 0 0 192.168.1.21:27017 192.168.1.14:45474
ESTABLISHED
tcp 0 0 192.168.1.21:27017 192.168.1.14:45475
ESTABLISHED
tcp 0 0 81.95.XXX.YYY:56553 82.194.NNN.MMM:10051
TIME_WAIT
tcp 0 0 81.95.XXX.YYY:41603 192.168.1.14:27017
ESTABLISHED
tcp 0 0 81.95.XXX.YYY:55396 192.168.1.14:30001
ESTABLISHED
tcp 0 0 192.168.1.21:49766 192.168.1.21:27017
ESTABLISHED
tcp 0 0 192.168.1.21:27017 192.168.1.12:52515
ESTABLISHED
tcp 0 0 81.95.XXX.YYY:33005 192.168.1.14:27017
TIME_WAIT
tcp 0 0 192.168.1.21:55431 192.168.1.21:27017
TIME_WAIT
tcp 0 0 192.168.1.21:55142 192.168.1.21:27017
TIME_WAIT
tcp 0 0 192.168.1.21:27017 192.168.1.17:24968
ESTABLISHED
tcp 0 0 192.168.1.21:27017 192.168.1.21:49766
ESTABLISHED
tcp6 0 0 :::22 :::*
LISTEN
tcp6 0 0 ::1:6010 :::*
LISTEN

In log file nothing critical, only open and closing connection:

Tue May 31 00:00:54 [conn389467608] end connection 192.168.1.12:62261
Tue May 31 00:00:54 [initandlisten] connection accepted from
192.168.1.12:62265 #389472401

Here is graph of connection number:
http://dl.dropbox.com/u/1028058/chart2.php.png

MongoDB v1.8.1

[Oleg Lobach]

> What state are the rest in? It could be that the network/firewall is
> closing connections on you.

Number of connections to the master at least 20.
In the local network (192.168.*.*) all ports are open.

[Scott Hernandez]

Can you post the serverStatus, and netstat -na numbers from the
secondary (slave) to show the connection numbers and endpoints?

[Oleg Lobach]

> Can you post the serverStatus, and netstat -na numbers from the
> secondary (slave) to show the connection numbers and endpoints?

#netstat -na

Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address
State

tcp 0 0 xxx.xxx.xxx.xxx:10050 0.0.0.0:*

LISTEN
tcp 0 0 192.168.1.21:27017 0.0.0.0:*
LISTEN
tcp 0 0 192.168.1.21:28017 0.0.0.0:*
LISTEN

tcp 0 0 xxx.xxx.xxx.xxx:80 xxx.xxx.xxx.xxx:50237
SYN_RECV
tcp 0 0 xxx.xxx.xxx.xxx:80 xxx.xxx.xxx.xxx:50054
SYN_RECV
tcp 0 0 xxx.xxx.xxx.xxx:80 xxx.xxx.xxx.xxx:1453
SYN_RECV
tcp 0 0 xxx.xxx.XXX.ZZZ:80 xxx.xxx.xxx.xxx:5330
SYN_RECV

tcp 0 0 0.0.0.0:22 0.0.0.0:*
LISTEN

tcp 0 176 xxx.xxx.xxx.xxx:22 xxx.xxx.xxx.xxx:39104
ESTABLISHED
tcp 0 0 192.168.1.21:34436 192.168.1.21:27017
TIME_WAIT
tcp 0 0 192.168.1.21:27017 192.168.1.12:56630
ESTABLISHED
tcp 0 0 xxx.xxx.xxx.xxx:43124 192.168.1.14:27017
ESTABLISHED
tcp 0 0 xxx.xxx.xxx.xxx:37228 xxx.xxx.xxx.xxx:10051
TIME_WAIT

tcp 0 0 192.168.1.21:27017 192.168.1.14:45474
ESTABLISHED
tcp 0 0 192.168.1.21:27017 192.168.1.14:45475
ESTABLISHED

tcp 0 0 xxx.xxx.xxx.xxx:41603 192.168.1.14:27017
ESTABLISHED
tcp 0 0 xxx.xxx.xxx.xxx:55434 192.168.1.14:27017
TIME_WAIT
tcp 0 0 xxx.xxx.XXX.YYY:55396 192.168.1.14:30001
ESTABLISHED
tcp 0 0 192.168.1.21:58160 192.168.1.21:27017
TIME_WAIT

tcp 0 0 192.168.1.21:49766 192.168.1.21:27017
ESTABLISHED
tcp 0 0 192.168.1.21:27017 192.168.1.12:52515
ESTABLISHED

tcp 0 0 192.168.1.21:34435 192.168.1.21:27017
TIME_WAIT

tcp 0 0 192.168.1.21:27017 192.168.1.21:49766
ESTABLISHED
tcp6 0 0 :::22 :::*
LISTEN

Active UNIX domain sockets (servers and established)
Proto RefCnt Flags Type State I-Node Path
unix 3 [ ] DGRAM 3504977065 /dev/log
unix 3 [ ] STREAM CONNECTED 3510035160
unix 3 [ ] STREAM CONNECTED 3510035159
unix 2 [ ] DGRAM 3510035157

master - 192.168.1.14
slave - 192.168.1.21

#mongostat

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 0 8.59g 9.09g
2.94g 0 0 0 0|0 0|0 320b 1k 15660
iii-prod SEC 17:42:11
*1 *0 *5 *0 0 1|0 0 8.59g 9.08g
2.94g 0 0 0 0|0 0|0 62b 1k 15660
iii-prod SEC 17:42:12
*0 *0 *1 *0 0 3|0 0 8.59g 9.08g
2.94g 0 0 0 0|0 0|0 320b 1k 15659
iii-prod SEC 17:42:13
*2 *0 *2 *0 0 1|0 0 8.59g 9.08g
2.94g 0 0 0 0|0 0|0 62b 1k 15660
iii-prod SEC 17:42:14
*16 *0 *0 *0 0 3|0 0 8.59g 9.09g
2.94g 0 0 0 0|0 0|0 320b 1k 15661
iii-prod SEC 17:42:15
*0 *0 *0 *0 0 1|0 1 8.59g 9.08g
2.94g 0 0 0 0|0 0|0 62b 1k 15659
iii-prod SEC 17:42:16
*0 *0 *2 *0 0 3|0 0 8.59g 9.09g
2.94g 0 0 0 0|0 0|0 320b 1k 15661
iii-prod SEC 17:42:17
*0 *0 *0 *0 0 1|0 0 8.59g 9.08g
2.94g 0 0 0 0|0 0|0 62b 1k 15659
iii-prod SEC 17:42:18
*0 *0 *0 *0 0 3|0 0 8.59g 9.08g
2.94g 0 0 0 0|0 0|0 320b 1k 15660
iii-prod SEC 17:42:19
*0 *0 *0 *0 0 1|0 0 8.59g 9.08g
2.94g 0 0 0 0|0 0|0 62b 1k 15659
iii-prod SEC 17:42:20

iii-prod:SECONDARY> db.serverStatus()
{
"host" : "****",
"version" : "1.8.1",
"process" : "mongod",
"uptime" : 5929572,
"uptimeEstimate" : 3068173,
"localTime" : ISODate("2011-07-08T13:44:32.407Z"),
"globalLock" : {
"totalTime" : 5929571804282,
"lockTime" : 170356288248,
"ratio" : 0.02872994777211035,
"currentQueue" : {
"total" : 0,
"readers" : 0,
"writers" : 0
},
"activeClients" : {
"total" : 0,
"readers" : 0,
"writers" : 0
}
},
"mem" : {
"bits" : 64,
"resident" : 3007,
"virtual" : 9307,
"supported" : true,
"mapped" : 8798
},
"connections" : {
"current" : 15660,
"available" : 340
},
"extra_info" : {
"note" : "fields vary by platform",
"heap_usage_bytes" : 200800,
"page_faults" : 1063032
},
"indexCounters" : {
"btree" : {
"accesses" : 53078720,
"hits" : 53078329,
"misses" : 391,
"resets" : 0,
"missRatio" : 0.000007366417276075986
}
},
"backgroundFlushing" : {
"flushes" : 98824,
"total_ms" : 120842328,
"average_ms" : 1222.803448555007,
"last_ms" : 478,
"last_finished" : ISODate("2011-07-08T13:44:16.480Z")
},
"cursors" : {
"totalOpen" : 0,
"clientCursors_size" : 0,
"timedOut" : 0
},
"network" : {
"bytesIn" : 780798846,
"bytesOut" : 966668030,
"numRequests" : 6125419
},
"repl" : {
"setName" : "iii-prod",
"ismaster" : false,
"secondary" : true,
"hosts" : [
"slave.local:27017",
"master.local:27017"
],
"arbiters" : [
"master.local:30001"
],
"primary" : "master.local:27017"
},
"opcountersRepl" : {
"insert" : 178593125,
"query" : 0,
"update" : 452508996,
"delete" : 14524141,
"getmore" : 0,
"command" : 8522
},
"opcounters" : {
"insert" : 0,
"query" : 98690,
"update" : 0,
"delete" : 0,
"getmore" : 0,
"command" : 6224067
},
"asserts" : {
"regular" : 0,
"warning" : 0,
"msg" : 0,
"user" : 8,
"rollovers" : 0
},
"writeBacksQueued" : false,
"ok" : 1

[Nat]

Didn't see that many connections in netstat though. Where are the rest of socket connections?

[Oleg Lobach]

> Didn't see that many connections in netstat though. Where are the rest of socket connections?

netstat does not show that a lot of connections, apparently they do not
exist in reality. But mongo believes that they are. Apparently so.

[Eliot Horowitz]

I think there was an issue in 1.8.1 where mongos' count may ge tout of sync.
Can you try 1.8.2.

[Oleg Lobach]

> I think there was an issue in 1.8.1 where mongos' count may ge tout of sync.

Where i can find this issue?

> Can you try 1.8.2.

No, we cann't do it right now.

>>> Didn't see that many connections in netstat though. Where are the rest of
>>> socket connections?
>>
>> netstat does not show that a lot of connections, apparently they do not
>> exist in reality. But mongo believes that they are. Apparently so.
>>
>>>