mongos timeouting if 1 node is down

[V]

Hello

Here is the case:

2 shards (2x2 replicas in each)

1a) mongo services get stopped on node A - system working OK

1b) os reinstalled on node A - system working OK

2) node A shutted down / rebooted - system gets timeouting (20-30 sec) and connection erroring

[root@zzz ~]# mongo localhost:27123/db -uuname -ppass

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

Mon Mar 19 11:57:44 uncaught exception: login failed

exception: login failed

[root@zzz ~]# mongo localhost:27123/db -uuname -ppass

MongoDB shell version: 2.0.3  <================ 20-30 SECONDS OF TIMEOUT BEFORE CONNECT

connecting to: localhost:27123/db

mongos>

If there is something with heartbeat here - how this can be fixed, if hearbeat is not configurable by end-user?

Heartbeats requests are sent out every couple of seconds and can either receive a response, get an error, or time out (after ~20 seconds). 

http://www.mongodb.org/display/DOCS/Replica+Set+Internals#ReplicaSetInternals-HeartbeatMonitoring 

Thanks

Vasyl

 

[V]

can anyone give me some update on this, pls?

1b) means - that only os reinstallation was performed and server was totally clean. none of additional services (including mongo) wasn't installed yet...

thanks

v

Понеділок, 19 березня 2012 р., 18:26:56 UTC+2 користувач V написав:

[Kristina Chodorow]

It sounds like MongoDB wasn't started up yet.  MongoDB sometimes preallocates journal files before beginning to listen on 27017, which can mean that it's a few minutes before anyone can connect to it.  If you attach the logs from startup until you were able to connect, we could probably confirm this theory.

[V]

Hello Kristina, 

It's a bit different situation. 

Some more hints.

Shard 01 [ A <> B ] ReplicaSet 

Shard 02 [ C <> D ] ReplicaSet

mongos on application side connecting to localhost

If we stop mongo services on any node (assume A) - system failing over to B fine until server A is up (respondable to pings)

But if we put the server A down (shutdown/reboot) - system hanging or timeouting (20-30 sec)

Понеділок, 19 березня 2012 р., 22:29:51 UTC+2 користувач Kristina Chodorow написав:

[Kristina Chodorow]

Oh, I see.  Unfortunately, I don't think you can do anything about it.  That timeout is not user configurable and that is very unlikely to change.  Sorry.

[V]

Thanks Kristina!

But I just don't understand... Really... 

Does it mean if any of sharding cluster nodes will have hardware related issue (shutted-down, self-rebooted, got broken) it'll cause connection problems for the end-user to the whole cluster system?

The same we are experiancing now..

V

Вівторок, 20 березня 2012 р., 00:06:06 UTC+2 користувач Kristina Chodorow написав:

Вівторок, 20 березня 2012 р., 00:06:06 UTC+2 користувач Kristina Chodorow написав:

[V]

Guys anything on this please...

It is really-really important...

I still can't get how 1 shutdowned node can compromise the whole sharding cluster...

What workarounds should be used if such situation happens?

Thanks

V

Понеділок, 19 березня 2012 р., 18:26:56 UTC+2 користувач V написав:

Hello

[Serge Smertin]

Same problem encountered here. Anyone has a clue if one of the nodes of replica set is down and everything is timeouting?..

[Kristina Chodorow]

Can you send the log from the mongos from before the server goes down, when it goes down (and you're getting timeouts), through when the cluster comes back online?

[V]

Hello Kristina

Sorry for long delay - we were upgrading all cluster nodes to ext4 - so there wasn't ability to do fair testing

Here is the info you asked

[root@mongos-server ~]# ping node_A | while read pong; do echo "$(date): $pong"; done   

Thu Mar 22 13:19:40 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=1 ttl=60 time=2.91 ms

Thu Mar 22 13:19:41 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=2 ttl=60 time=2.73 ms

Thu Mar 22 13:19:42 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=3 ttl=60 time=2.63 ms

Thu Mar 22 13:19:43 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=4 ttl=60 time=2.54 ms

Thu Mar 22 13:19:44 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=5 ttl=60 time=2.61 ms

Thu Mar 22 13:19:45 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=6 ttl=60 time=2.83 ms

Thu Mar 22 13:19:46 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=7 ttl=60 time=2.64 ms

Thu Mar 22 13:19:47 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=8 ttl=60 time=2.80 ms

Thu Mar 22 13:19:48 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=9 ttl=60 time=2.72 ms

Thu Mar 22 13:19:49 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=10 ttl=60 time=2.68 ms

Thu Mar 22 13:19:50 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=11 ttl=60 time=2.59 ms

Thu Mar 22 13:19:51 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=12 ttl=60 time=2.64 ms

Thu Mar 22 13:19:52 EDT 2012: Request timed out.

----- REBOOTING 1 MIN GAP -----------------------------------------------------------------------

Thu Mar 22 13:20:55 EDT 2012: Request timed out.

Thu Mar 22 13:20:56 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=77 ttl=60 time=2.82 ms

Thu Mar 22 13:20:57 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=78 ttl=60 time=2.78 ms

Thu Mar 22 13:20:58 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=79 ttl=60 time=2.74 ms

Thu Mar 22 13:20:59 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=80 ttl=60 time=2.56 ms

Thu Mar 22 13:21:00 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=81 ttl=60 time=2.66 ms

Thu Mar 22 13:21:01 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=82 ttl=60 time=2.73 ms

Thu Mar 22 13:21:02 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=83 ttl=60 time=2.74 ms

Thu Mar 22 13:21:03 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=84 ttl=60 time=2.67 ms

Thu Mar 22 13:21:04 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=85 ttl=60 time=2.62 ms

Thu Mar 22 13:21:05 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=86 ttl=60 time=2.70 ms

Thu Mar 22 13:21:06 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=87 ttl=60 time=2.67 ms

Thu Mar 22 13:21:07 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=88 ttl=60 time=2.68 ms

Thu Mar 22 13:21:08 EDT 2012: 64 bytes from node_A (12.34.56.78): icmp_seq=89 ttl=60 time=2.54 ms

########################################################################################

------------------- MONGOS-SERVER LOG START --------------------------

Thu Mar 22 13:18:41 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:18:41 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:18:41 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:18:42 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:18:42 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:19:12 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:19:12 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:19:12 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:19:12 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:19:12 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:19:42 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:19:42 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:19:42 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:19:42 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:19:42 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:19:50 [WriteBackListener-node_A:27234] DBClientCursor::init call() failed

Thu Mar 22 13:19:50 [WriteBackListener-node_A:27234] WriteBackListener exception : DBClientBase::findN: transport error: node_A:27234 query: { writebacklisten: ObjectId('4f6b5d0f7c830556fb779771') }

Thu Mar 22 13:19:50 [conn243] Socket recv() errno:104 Connection reset by peer 12.34.56.78:27234

Thu Mar 22 13:19:50 [conn243] SocketException: remote: 12.34.56.78:27234 error: 9001 socket exception [1] server [12.34.56.78:27234]

Thu Mar 22 13:19:50 [conn243] DBClientCursor::init call() failed

Thu Mar 22 13:19:50 [conn243] trying reconnect to node_A:27234

Thu Mar 22 13:19:50 [conn243] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:19:51 [WriteBackListener-node_A:27234] WriteBackListener exception : socket exception

Thu Mar 22 13:19:51 [conn243] ReplicaSetMonitor::_checkConnection: caught exception node_A:27234 socket exception

Thu Mar 22 13:19:51 [conn243] ReplicaSetMonitor::_checkConnection: node_C:27234 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "node_C:27234", "node_A:27234" ], arbiters: [ "arbiter_AC:27321" ], primary: "node_A:27234", me: "node_C:27234", maxBsonObjectSize: 16777216, ok: 1.0 }

Thu Mar 22 13:19:52 [conn243] trying reconnect to node_A:27234

Thu Mar 22 13:19:57 [conn243] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:19:57 [ReplicaSetMonitorWatcher] trying reconnect to node_A:27234

Thu Mar 22 13:20:02 [ReplicaSetMonitorWatcher] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:02 [ReplicaSetMonitorWatcher] trying reconnect to node_A:27234

Thu Mar 22 13:20:07 [ReplicaSetMonitorWatcher] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:07 [conn243] trying reconnect to node_A:27234

Thu Mar 22 13:20:12 [conn243] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:12 [conn243] ReplicaSetMonitor::_checkConnection: caught exception node_A:27234 socket exception

Thu Mar 22 13:20:12 [conn243] ReplicaSetMonitor::_checkConnection: node_C:27234 { setName: "repSet1", ismaster: true, secondary: false, hosts: [ "node_C:27234", "node_A:27234" ], arbiters: [ "arbiter_AC:27321" ], primary: "node_C:27234", me: "node_C:27234", maxBsonObjectSize: 16777216, ok: 1.0 }

Thu Mar 22 13:20:12 [conn243] trying reconnect to node_A:27234

Thu Mar 22 13:20:17 [conn243] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:17 [Balancer] trying reconnect to node_A:27234

Thu Mar 22 13:20:22 [Balancer] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:22 [Balancer] trying reconnect to node_A:27234

Thu Mar 22 13:20:27 [Balancer] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:27 [conn243] trying reconnect to node_A:27234

Thu Mar 22 13:20:27 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:20:27 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:20:27 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:20:27 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:20:27 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:20:32 [conn243] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:32 [conn244] trying reconnect to node_A:27234

Thu Mar 22 13:20:37 [conn244] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:37 [conn244] trying reconnect to node_A:27234

Thu Mar 22 13:20:42 [conn244] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:42 [conn245] trying reconnect to node_A:27234

Thu Mar 22 13:20:47 [conn245] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:47 [conn245] trying reconnect to node_A:27234

Thu Mar 22 13:20:52 [conn245] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:52 [ReplicaSetMonitorWatcher] trying reconnect to node_A:27234

Thu Mar 22 13:20:57 [ReplicaSetMonitorWatcher] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:57 [conn244] trying reconnect to node_A:27234

Thu Mar 22 13:20:57 [conn244] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:20:57 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:20:57 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:20:57 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:20:57 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:20:57 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:20:59 [conn248] trying reconnect to node_A:27234

Thu Mar 22 13:20:59 [conn248] reconnect node_A:27234 failed couldn't connect to server node_A:27234

Thu Mar 22 13:21:02 [conn249] trying reconnect to node_A:27234

Thu Mar 22 13:21:02 [conn249] reconnect node_A:27234 ok

Thu Mar 22 13:21:07 [WriteBackListener-node_C:27234] DBClientCursor::init call() failed

Thu Mar 22 13:21:07 [WriteBackListener-node_C:27234] WriteBackListener exception : DBClientBase::findN: transport error: node_C:27234 query: { writebacklisten: ObjectId('4f6b5d0f7c830556fb779771') }

Thu Mar 22 13:21:07 [ReplicaSetMonitorWatcher] Socket recv() errno:104 Connection reset by peer 11.22.33.44:27234

Thu Mar 22 13:21:07 [ReplicaSetMonitorWatcher] SocketException: remote: 11.22.33.44:27234 error: 9001 socket exception [1] server [11.22.33.44:27234]

Thu Mar 22 13:21:07 [ReplicaSetMonitorWatcher] DBClientCursor::init call() failed

Thu Mar 22 13:21:07 [ReplicaSetMonitorWatcher] trying reconnect to node_C:27234

Thu Mar 22 13:21:07 [ReplicaSetMonitorWatcher] reconnect node_C:27234 ok

Thu Mar 22 13:21:08 [ReplicaSetMonitorWatcher] ReplicaSetMonitor::_checkConnection: node_A:27234 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "node_A:27234", "node_C:27234" ], arbiters: [ "arbiter_AC:27321" ], primary: "node_C:27234", me: "node_A:27234", maxBsonObjectSize: 16777216, ok: 1.0 }

Thu Mar 22 13:21:08 [ReplicaSetMonitorWatcher] ReplicaSetMonitor::_checkConnection: node_C:27234 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "node_C:27234", "node_A:27234" ], arbiters: [ "arbiter_AC:27321" ], me: "node_C:27234", maxBsonObjectSize: 16777216, ok: 1.0 }

Thu Mar 22 13:21:26 [WriteBackListener-node_A:27234] WriteBackListener exception : socket exception

Thu Mar 22 13:21:27 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:21:27 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:21:27 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:21:27 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:21:27 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:21:57 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:21:57 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:21:57 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:21:57 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:21:57 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:22:27 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:22:27 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:22:27 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:22:27 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:22:27 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:22:57 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:22:57 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:22:57 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:22:57 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:22:57 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Thu Mar 22 13:23:28 [Balancer] SyncClusterConnection connecting to [config1:27123]

Thu Mar 22 13:23:28 [Balancer] SyncClusterConnection connecting to [config2:27123]

Thu Mar 22 13:23:28 [Balancer] SyncClusterConnection connecting to [config3:27123]

Thu Mar 22 13:23:28 [Balancer] ~ScopedDbConnection: _conn != null

Thu Mar 22 13:23:28 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

------------------ MONGOS-SERVER LOG END --------------------------

Thanks

Vasyl

Вівторок, 20 березня 2012 р., 16:55:08 UTC+2 користувач Kristina Chodorow написав:

[Kristina Chodorow]

This is looking like a bug, but can you try it one more time and try to connect with the shell, so I can see when it finally is able to reconnect?

[V]

Hello Kristina.

Here is info u asked

[root@mongos-server ~]# ping nodeA | xargs -n1 -i bash -c 'echo `date +"%Y-%m-%d %H:%M:%S:%N"`" {}"' | tee ping_output

2012-03-23 09:25:00:508130997 64 bytes from nodeA (12.34.56.78): icmp_seq=107 ttl=60 time=2.68 ms

2012-03-23 09:25:01:720771633 64 bytes from nodeA (12.34.56.78): icmp_seq=108 ttl=60 time=2.65 ms

2012-03-23 09:25:02:467791562 64 bytes from nodeA (12.34.56.78): icmp_seq=109 ttl=60 time=2.66 ms

2012-03-23 09:25:03:471354833 64 bytes from nodeA (12.34.56.78): icmp_seq=110 ttl=60 time=2.74 ms

2012-03-23 09:25:04:468653054 64 bytes from nodeA (12.34.56.78): icmp_seq=111 ttl=60 time=2.63 ms

2012-03-23 09:25:05:469937574 64 bytes from nodeA (12.34.56.78): icmp_seq=112 ttl=60 time=2.62 ms

2012-03-23 09:25:06:475103930 64 bytes from nodeA (12.34.56.78): icmp_seq=113 ttl=60 time=2.57 ms

2012-03-23 09:25:07:471359477 64 bytes from nodeA (12.34.56.78): icmp_seq=114 ttl=60 time=2.80 ms

2012-03-23 09:25:08:471606052 64 bytes from nodeA (12.34.56.78): icmp_seq=115 ttl=60 time=2.90 ms

2012-03-23 09:25:09:472789922 64 bytes from nodeA (12.34.56.78): icmp_seq=116 ttl=60 time=2.79 ms

2012-03-23 09:25:10:473661106 64 bytes from nodeA (12.34.56.78): icmp_seq=117 ttl=60 time=2.61 ms

2012-03-23 09:25:11:475200468 64 bytes from nodeA (12.34.56.78): icmp_seq=118 ttl=60 time=2.67 ms

2012-03-23 09:25:12:475051336 64 bytes from nodeA (12.34.56.78): icmp_seq=119 ttl=60 time=2.65 ms

2012-03-23 09:25:13:605527293 64 bytes from nodeA (12.34.56.78): icmp_seq=120 ttl=60 time=2.61 ms

2012-03-23 09:25:14:476882545 64 bytes from nodeA (12.34.56.78): icmp_seq=121 ttl=60 time=2.70 ms

2012-03-23 09:25:15:477859606 64 bytes from nodeA (12.34.56.78): icmp_seq=122 ttl=60 time=2.66 ms

2012-03-23 09:25:16:479070162 64 bytes from nodeA (12.34.56.78): icmp_seq=123 ttl=60 time=2.80 ms

----------------- REBOOT ------------------------------------------------------------------------

2012-03-23 09:33:00:484940470 64 bytes from nodeA (12.34.56.78): icmp_seq=587 ttl=60 time=2.62 ms

2012-03-23 09:33:01:485977973 64 bytes from nodeA (12.34.56.78): icmp_seq=588 ttl=60 time=2.62 ms

2012-03-23 09:33:02:486268006 64 bytes from nodeA (12.34.56.78): icmp_seq=589 ttl=60 time=2.67 ms

2012-03-23 09:33:03:486184832 64 bytes from nodeA (12.34.56.78): icmp_seq=590 ttl=60 time=2.53 ms

2012-03-23 09:33:04:608540095 64 bytes from nodeA (12.34.56.78): icmp_seq=591 ttl=60 time=2.66 ms

2012-03-23 09:33:05:489840014 64 bytes from nodeA (12.34.56.78): icmp_seq=592 ttl=60 time=2.78 ms

2012-03-23 09:33:06:490980271 64 bytes from nodeA (12.34.56.78): icmp_seq=593 ttl=60 time=2.63 ms

2012-03-23 09:33:07:491425395 64 bytes from nodeA (12.34.56.78): icmp_seq=594 ttl=60 time=2.62 ms

2012-03-23 09:33:08:491699530 64 bytes from nodeA (12.34.56.78): icmp_seq=595 ttl=60 time=2.68 ms

2012-03-23 09:33:09:525406454 64 bytes from nodeA (12.34.56.78): icmp_seq=596 ttl=60 time=2.67 ms

2012-03-23 09:33:10:493673437 64 bytes from nodeA (12.34.56.78): icmp_seq=597 ttl=60 time=2.59 ms

2012-03-23 09:33:11:494773518 64 bytes from nodeA (12.34.56.78): icmp_seq=598 ttl=60 time=2.66 ms

2012-03-23 09:33:12:494832811 64 bytes from nodeA (12.34.56.78): icmp_seq=599 ttl=60 time=2.59 ms

2012-03-23 09:33:13:495089890 64 bytes from nodeA (12.34.56.78): icmp_seq=600 ttl=60 time=2.56 ms

2012-03-23 09:33:14:495481978 64 bytes from nodeA (12.34.56.78): icmp_seq=601 ttl=60 time=2.63 ms

2012-03-23 09:33:15:496584851 64 bytes from nodeA (12.34.56.78): icmp_seq=602 ttl=60 time=2.66 ms

2012-03-23 09:33:16:497891583 64 bytes from nodeA (12.34.56.78): icmp_seq=603 ttl=60 time=2.57 ms

2012-03-23 09:33:17:497792174 64 bytes from nodeA (12.34.56.78): icmp_seq=604 ttl=60 time=2.57 ms

2012-03-23 09:33:18:497993398 64 bytes from nodeA (12.34.56.78): icmp_seq=605 ttl=60 time=2.69 ms

2012-03-23 09:33:19:499115472 64 bytes from nodeA (12.34.56.78): icmp_seq=606 ttl=60 time=2.66 ms

2012-03-23 09:33:20:500276525 64 bytes from nodeA (12.34.56.78): icmp_seq=607 ttl=60 time=2.58 ms

2012-03-23 09:33:21:500748566 64 bytes from nodeA (12.34.56.78): icmp_seq=608 ttl=60 time=2.70 ms

2012-03-23 09:33:22:500896502 64 bytes from nodeA (12.34.56.78): icmp_seq=609 ttl=60 time=2.74 ms

2012-03-23 09:33:23:501740905 64 bytes from nodeA (12.34.56.78): icmp_seq=610 ttl=60 time=2.55 ms

2012-03-23 09:33:24:502974606 64 bytes from nodeA (12.34.56.78): icmp_seq=611 ttl=60 time=2.66 ms

2012-03-23 09:33:25:558986105 64 bytes from nodeA (12.34.56.78): icmp_seq=612 ttl=60 time=2.58 ms

2012-03-23 09:33:26:504548532 64 bytes from nodeA (12.34.56.78): icmp_seq=613 ttl=60 time=2.87 ms

2012-03-23 09:33:27:505527270 64 bytes from nodeA (12.34.56.78): icmp_seq=614 ttl=60 time=2.66 ms

2012-03-23 09:33:28:506784628 64 bytes from nodeA (12.34.56.78): icmp_seq=615 ttl=60 time=2.52 ms

2012-03-23 09:33:29:517587462 64 bytes from nodeA (12.34.56.78): icmp_seq=616 ttl=60 time=2.59 ms

2012-03-23 09:33:30:509184748 64 bytes from nodeA (12.34.56.78): icmp_seq=617 ttl=60 time=2.73 ms

#################################################################################################

[root@mongos-server ~]# while [ true ]; do date +"%Y-%m-%d %H:%M:%S:%N" && time mongo localhost:27123/db -uusername -ppassword --eval "db.collection.count()" && date +"%Y-%m-%d %H:%M:%S:%N"; echo '-----------------------------'; sleep 1; done  2>&1 | tee mongos_output

2012-03-23 09:25:00:458814057

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.121s

user    0m0.048s

sys     0m0.006s

2012-03-23 09:25:00:582081467

-----------------------------

2012-03-23 09:25:01:588353027

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.235s

user    0m0.050s

sys     0m0.006s

2012-03-23 09:25:01:824823399

-----------------------------

2012-03-23 09:25:02:828153882

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.172s

user    0m0.049s

sys     0m0.007s

2012-03-23 09:25:03:002198838

-----------------------------

2012-03-23 09:25:04:050667721

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.152s

user    0m0.050s

sys     0m0.003s

2012-03-23 09:25:04:204023038

-----------------------------

2012-03-23 09:25:05:208573370

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.120s

user    0m0.047s

sys     0m0.007s

2012-03-23 09:25:05:330710054

-----------------------------

2012-03-23 09:25:06:335180234

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.241s

user    0m0.051s

sys     0m0.009s

2012-03-23 09:25:06:577760085

-----------------------------

2012-03-23 09:25:07:580939265

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.170s

user    0m0.046s

sys     0m0.008s

2012-03-23 09:25:07:752011908

-----------------------------

2012-03-23 09:25:08:758361605

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.201s

user    0m0.051s

sys     0m0.005s

2012-03-23 09:25:08:960934402

-----------------------------

2012-03-23 09:25:09:964437778

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.121s

user    0m0.046s

sys     0m0.006s

2012-03-23 09:25:10:087176130

-----------------------------

2012-03-23 09:25:11:094296543

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.225s

user    0m0.047s

sys     0m0.009s

2012-03-23 09:25:11:320919152

-----------------------------

2012-03-23 09:25:12:324876097

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.121s

user    0m0.050s

sys     0m0.005s

2012-03-23 09:25:12:447372120

-----------------------------

2012-03-23 09:25:13:590015570

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.177s

user    0m0.045s

sys     0m0.008s

2012-03-23 09:25:13:768880571

-----------------------------

2012-03-23 09:25:14:773266370

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.121s

user    0m0.047s

sys     0m0.008s

2012-03-23 09:25:14:896052434

-------------------------------------------- REBOOT --------------------------------------------

2012-03-23 09:25:15:932604215

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    3m12.295s

user    0m0.049s

sys     0m0.004s

2012-03-23 09:28:28:229307913

-----------------------------

2012-03-23 09:28:29:233631999

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    3m39.289s

user    0m0.046s

sys     0m0.007s

2012-03-23 09:32:08:524013516

-----------------------------

2012-03-23 09:32:09:528561932

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m52.669s

user    0m0.043s

sys     0m0.010s

2012-03-23 09:33:02:199118681

-----------------------------

2012-03-23 09:33:03:203033931

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.130s

user    0m0.045s

sys     0m0.008s

2012-03-23 09:33:03:334896508

-----------------------------

2012-03-23 09:33:04:339247030

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.363s

user    0m0.045s

sys     0m0.009s

2012-03-23 09:33:04:703977004

-----------------------------

2012-03-23 09:33:05:707444021

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.158s

user    0m0.047s

sys     0m0.007s

2012-03-23 09:33:05:866553989

-----------------------------

2012-03-23 09:33:06:981768503

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.411s

user    0m0.049s

sys     0m0.007s

2012-03-23 09:33:07:394181159

-----------------------------

2012-03-23 09:33:08:398958126

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.155s

user    0m0.047s

sys     0m0.007s

2012-03-23 09:33:08:555807828

-----------------------------

2012-03-23 09:33:09:560103505

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.224s

user    0m0.045s

sys     0m0.007s

2012-03-23 09:33:09:785517038

-----------------------------

2012-03-23 09:33:10:790350098

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.154s

user    0m0.047s

sys     0m0.008s

2012-03-23 09:33:10:945636587

-----------------------------

2012-03-23 09:33:11:951211041

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.290s

user    0m0.050s

sys     0m0.006s

2012-03-23 09:33:12:242933986

-----------------------------

2012-03-23 09:33:13:246869806

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

Fri Mar 23 09:33:19 uncaught exception: login failed

exception: login failed

real    0m6.142s

user    0m0.046s

sys     0m0.005s

-----------------------------

2012-03-23 09:33:20:394254759

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m1.189s

user    0m0.047s

sys     0m0.007s

2012-03-23 09:33:21:585046967

-----------------------------

2012-03-23 09:33:22:589401554

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.122s

user    0m0.049s

sys     0m0.004s

2012-03-23 09:33:22:712926960

-----------------------------

2012-03-23 09:33:23:717576819

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.225s

user    0m0.049s

sys     0m0.007s

2012-03-23 09:33:23:943913305

-----------------------------

2012-03-23 09:33:24:948848407

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.125s

user    0m0.048s

sys     0m0.007s

2012-03-23 09:33:25:076058691

-----------------------------

2012-03-23 09:33:26:080120856

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.120s

user    0m0.046s

sys     0m0.007s

2012-03-23 09:33:26:201615728

-----------------------------

2012-03-23 09:33:27:205483996

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.122s

user    0m0.048s

sys     0m0.008s

2012-03-23 09:33:27:329763137

-----------------------------

2012-03-23 09:33:28:333506769

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.120s

user    0m0.048s

sys     0m0.006s

2012-03-23 09:33:28:455411517

-----------------------------

2012-03-23 09:33:29:459644469

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.126s

user    0m0.045s

sys     0m0.011s

2012-03-23 09:33:29:587789643

-----------------------------

2012-03-23 09:33:30:592764068

MongoDB shell version: 2.0.3

connecting to: localhost:27123/db

2095

real    0m0.119s

user    0m0.046s

sys     0m0.007s

2012-03-23 09:33:30:713973635

-----------------------------

Thanks

Vasyl

Четвер, 22 березня 2012 р., 22:03:14 UTC+2 користувач Kristina Chodorow написав:

[Kristina Chodorow]

I need the mongos log from that time.

[V]

Here is the log

 --------------- MONGOS LOG START -----------------

Fri Mar 23 09:24:32 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:25:02 [Balancer] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:25:02 [Balancer] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:25:02 [Balancer] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:25:02 [Balancer] ~ScopedDbConnection: _conn != null

Fri Mar 23 09:25:02 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:25:15 [WriteBackListener-nodeA:27123] DBClientCursor::init call() failed

Fri Mar 23 09:25:15 [WriteBackListener-nodeA:27123] WriteBackListener exception : DBClientBase::findN: transport error: nodeA:27123 query: { writebacklisten: ObjectId('4f6b5d0f7c830556fb779771') }

Fri Mar 23 09:25:15 [ReplicaSetMonitorWatcher] DBClientCursor::init call() failed

Fri Mar 23 09:25:15 [ReplicaSetMonitorWatcher] trying reconnect to nodeA:27123

Fri Mar 23 09:25:15 [ReplicaSetMonitorWatcher] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:16 [WriteBackListener-nodeA:27123] WriteBackListener exception : socket exception

Fri Mar 23 09:25:16 [ReplicaSetMonitorWatcher] ReplicaSetMonitor::_checkConnection: caught exception nodeA:27123 socket exception

Fri Mar 23 09:25:16 [ReplicaSetMonitorWatcher] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:25:16 [conn54768] ReplicaSetMonitor::_checkConnection: caught exception nodeA:27123 socket exception

Fri Mar 23 09:25:16 [conn54768] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:25:16 [conn54769] ReplicaSetMonitor::_checkConnection: caught exception nodeA:27123 socket exception

Fri Mar 23 09:25:16 [conn54769] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:25:17 [conn54768] trying reconnect to nodeA:27123

Fri Mar 23 09:25:22 [conn54768] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:22 [conn54768] trying reconnect to nodeA:27123

Fri Mar 23 09:25:27 [conn54768] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:27 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:25:32 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:32 [conn54770] trying reconnect to nodeA:27123

Fri Mar 23 09:25:37 [conn54770] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:37 [conn54769] trying reconnect to nodeA:27123

Fri Mar 23 09:25:42 [conn54769] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:42 [conn54769] trying reconnect to nodeA:27123

Fri Mar 23 09:25:47 [conn54769] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:47 [Balancer] trying reconnect to nodeA:27123

Fri Mar 23 09:25:52 [Balancer] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:52 [Balancer] trying reconnect to nodeA:27123

Fri Mar 23 09:25:57 [Balancer] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:25:57 [conn54771] trying reconnect to nodeA:27123

Fri Mar 23 09:25:58 [Balancer] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:25:58 [Balancer] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:25:58 [Balancer] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:25:58 [Balancer] ~ScopedDbConnection: _conn != null

Fri Mar 23 09:25:58 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:26:02 [conn54771] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:02 [conn54771] trying reconnect to nodeA:27123

Fri Mar 23 09:26:07 [conn54771] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:08 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:26:13 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:13 [conn54768] trying reconnect to nodeA:27123

Fri Mar 23 09:26:18 [conn54768] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:18 [conn54769] trying reconnect to nodeA:27123

Fri Mar 23 09:26:23 [conn54769] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:23 [conn54770] trying reconnect to nodeA:27123

Fri Mar 23 09:26:28 [conn54770] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:28 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:26:33 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:33 [conn54774] trying reconnect to nodeA:27123

Fri Mar 23 09:26:38 [conn54774] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:38 [conn54774] trying reconnect to nodeA:27123

Fri Mar 23 09:26:43 [conn54774] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:43 [conn54771] trying reconnect to nodeA:27123

Fri Mar 23 09:26:48 [conn54771] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:48 [conn54771] trying reconnect to nodeA:27123

Fri Mar 23 09:26:53 [conn54771] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:53 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:26:58 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:26:58 [conn54769] trying reconnect to nodeA:27123

Fri Mar 23 09:27:03 [conn54769] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:03 [ReplicaSetMonitorWatcher] trying reconnect to nodeA:27123

Fri Mar 23 09:27:08 [ReplicaSetMonitorWatcher] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:08 [conn54775] trying reconnect to nodeA:27123

Fri Mar 23 09:27:13 [conn54775] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:13 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:27:18 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:18 [conn54769] trying reconnect to nodeA:27123

Fri Mar 23 09:27:23 [conn54769] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:23 [conn54769] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:27:23 [Balancer] trying reconnect to nodeA:27123

Fri Mar 23 09:27:23 [conn54769] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:27:23 [conn54769] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:27:28 [Balancer] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:28 [conn54773] trying reconnect to nodeA:27123

Fri Mar 23 09:27:28 [Balancer] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:27:28 [Balancer] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:27:28 [Balancer] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:27:28 [Balancer] ~ScopedDbConnection: _conn != null

Fri Mar 23 09:27:28 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:27:33 [conn54773] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:33 [conn54773] trying reconnect to nodeA:27123

Fri Mar 23 09:27:38 [conn54773] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:38 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:27:43 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:43 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:27:48 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:48 [conn54771] trying reconnect to nodeA:27123

Fri Mar 23 09:27:53 [conn54771] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:53 [conn54775] trying reconnect to nodeA:27123

Fri Mar 23 09:27:58 [conn54775] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:27:58 [conn54775] trying reconnect to nodeA:27123

Fri Mar 23 09:28:03 [conn54775] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:03 [conn54770] trying reconnect to nodeA:27123

Fri Mar 23 09:28:08 [conn54770] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:08 [conn54770] trying reconnect to nodeA:27123

Fri Mar 23 09:28:13 [conn54770] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:13 [ReplicaSetMonitorWatcher] trying reconnect to nodeA:27123

Fri Mar 23 09:28:18 [ReplicaSetMonitorWatcher] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:18 [conn54769] trying reconnect to nodeA:27123

Fri Mar 23 09:28:23 [conn54769] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:23 [conn54769] trying reconnect to nodeA:27123

Fri Mar 23 09:28:27 [WriteBackListener-nodeA:27123] WriteBackListener exception : socket exception

Fri Mar 23 09:28:27 [WriteBackListener-nodeA:27123] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:28:27 [WriteBackListener-nodeA:27123] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:28:27 [WriteBackListener-nodeA:27123] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:28:28 [conn54769] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:28 [conn54771] trying reconnect to nodeA:27123

Fri Mar 23 09:28:33 [conn54771] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:33 [conn54771] trying reconnect to nodeA:27123

Fri Mar 23 09:28:38 [conn54771] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:38 [conn54773] trying reconnect to nodeA:27123

Fri Mar 23 09:28:43 [conn54773] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:43 [conn54772] trying reconnect to nodeA:27123

Fri Mar 23 09:28:48 [conn54772] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:48 [ReplicaSetMonitorWatcher] trying reconnect to nodeA:27123

Fri Mar 23 09:28:53 [ReplicaSetMonitorWatcher] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:53 [Balancer] trying reconnect to nodeA:27123

Fri Mar 23 09:28:58 [Balancer] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:28:58 [conn54776] trying reconnect to nodeA:27123

Fri Mar 23 09:28:58 [Balancer] ~ScopedDbConnection: _conn != null

Fri Mar 23 09:28:58 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:29:03 [conn54776] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:03 [conn54776] trying reconnect to nodeA:27123

Fri Mar 23 09:29:08 [conn54776] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:08 [conn54778] trying reconnect to nodeA:27123

Fri Mar 23 09:29:13 [conn54778] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:13 [conn54779] trying reconnect to nodeA:27123

Fri Mar 23 09:29:18 [conn54779] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:18 [conn54777] trying reconnect to nodeA:27123

Fri Mar 23 09:29:23 [conn54777] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:23 [conn54777] trying reconnect to nodeA:27123

Fri Mar 23 09:29:28 [conn54777] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:28 [conn54781] trying reconnect to nodeA:27123

Fri Mar 23 09:29:33 [conn54781] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:33 [conn54781] trying reconnect to nodeA:27123

Fri Mar 23 09:29:38 [conn54781] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:38 [conn54778] trying reconnect to nodeA:27123

Fri Mar 23 09:29:43 [conn54778] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:43 [conn54778] trying reconnect to nodeA:27123

Fri Mar 23 09:29:48 [conn54778] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:48 [conn54780] trying reconnect to nodeA:27123

Fri Mar 23 09:29:53 [conn54780] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:53 [conn54777] trying reconnect to nodeA:27123

Fri Mar 23 09:29:58 [conn54777] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:29:58 [conn54770] trying reconnect to nodeA:27123

Fri Mar 23 09:30:03 [conn54770] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:03 [conn54782] trying reconnect to nodeA:27123

Fri Mar 23 09:30:08 [conn54782] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:08 [conn54782] trying reconnect to nodeA:27123

Fri Mar 23 09:30:13 [conn54782] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:13 [conn54779] trying reconnect to nodeA:27123

Fri Mar 23 09:30:18 [conn54779] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:18 [conn54779] trying reconnect to nodeA:27123

Fri Mar 23 09:30:23 [conn54779] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:23 [conn54780] trying reconnect to nodeA:27123

Fri Mar 23 09:30:28 [conn54780] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:28 [conn54780] trying reconnect to nodeA:27123

Fri Mar 23 09:30:33 [conn54780] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:33 [conn54770] trying reconnect to nodeA:27123

Fri Mar 23 09:30:38 [conn54770] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:38 [conn54770] trying reconnect to nodeA:27123

Fri Mar 23 09:30:43 [conn54770] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:43 [conn54774] trying reconnect to nodeA:27123

Fri Mar 23 09:30:48 [conn54774] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:48 [conn54773] trying reconnect to nodeA:27123

Fri Mar 23 09:30:53 [conn54773] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:53 [ReplicaSetMonitorWatcher] trying reconnect to nodeA:27123

Fri Mar 23 09:30:58 [ReplicaSetMonitorWatcher] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:30:58 [conn54780] trying reconnect to nodeA:27123

Fri Mar 23 09:31:03 [conn54780] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:03 [conn54781] trying reconnect to nodeA:27123

Fri Mar 23 09:31:08 [conn54781] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:08 [conn54783] trying reconnect to nodeA:27123

Fri Mar 23 09:31:13 [conn54783] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:13 [conn54783] trying reconnect to nodeA:27123

Fri Mar 23 09:31:18 [conn54783] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:18 [conn54778] trying reconnect to nodeA:27123

Fri Mar 23 09:31:23 [conn54778] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:23 [Balancer] trying reconnect to nodeA:27123

Fri Mar 23 09:31:28 [Balancer] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:28 [conn54776] trying reconnect to nodeA:27123

Fri Mar 23 09:31:28 [Balancer] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:31:28 [Balancer] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:31:28 [Balancer] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:31:28 [Balancer] ~ScopedDbConnection: _conn != null

Fri Mar 23 09:31:28 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:31:33 [conn54776] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:33 [conn54780] trying reconnect to nodeA:27123

Fri Mar 23 09:31:38 [conn54780] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:38 [conn54780] trying reconnect to nodeA:27123

Fri Mar 23 09:31:39 [WriteBackListener-nodeA:27123] WriteBackListener exception : socket exception

Fri Mar 23 09:31:43 [conn54780] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:43 [conn54782] trying reconnect to nodeA:27123

Fri Mar 23 09:31:48 [conn54782] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:48 [conn54786] trying reconnect to nodeA:27123

Fri Mar 23 09:31:53 [conn54786] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:53 [conn54786] trying reconnect to nodeA:27123

Fri Mar 23 09:31:58 [conn54786] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:31:58 [conn54778] trying reconnect to nodeA:27123

Fri Mar 23 09:32:03 [conn54778] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:03 [conn54778] trying reconnect to nodeA:27123

Fri Mar 23 09:32:08 [conn54778] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:08 [conn54784] trying reconnect to nodeA:27123

Fri Mar 23 09:32:13 [conn54784] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:13 [ReplicaSetMonitorWatcher] trying reconnect to nodeA:27123

Fri Mar 23 09:32:18 [ReplicaSetMonitorWatcher] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:18 [conn54788] trying reconnect to nodeA:27123

Fri Mar 23 09:32:23 [conn54788] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:23 [conn54788] trying reconnect to nodeA:27123

Fri Mar 23 09:32:28 [conn54788] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:28 [conn54786] trying reconnect to nodeA:27123

Fri Mar 23 09:32:33 [conn54786] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:33 [conn54777] trying reconnect to nodeA:27123

Fri Mar 23 09:32:38 [conn54777] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:38 [conn54776] trying reconnect to nodeA:27123

Fri Mar 23 09:32:43 [conn54776] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:43 [conn54781] trying reconnect to nodeA:27123

Fri Mar 23 09:32:48 [conn54781] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:48 [conn54787] trying reconnect to nodeA:27123

Fri Mar 23 09:32:53 [conn54787] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:53 [conn54782] trying reconnect to nodeA:27123

Fri Mar 23 09:32:58 [conn54782] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:32:58 [conn54785] trying reconnect to nodeA:27123

Fri Mar 23 09:33:01 [conn54785] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:33:01 [conn54785] trying reconnect to nodeA:27123

Fri Mar 23 09:33:01 [conn54785] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:33:01 [Balancer] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:33:01 [Balancer] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:33:01 [Balancer] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:33:01 [Balancer] ~ScopedDbConnection: _conn != null

Fri Mar 23 09:33:01 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:33:02 [conn54776] DBException in process: socket exception

Fri Mar 23 09:33:02 [conn54776] SocketException handling request, closing client connection: 9001 socket exception [2] server [127.0.0.1:53296] 

Fri Mar 23 09:33:02 [conn54773] DBException in process: socket exception

Fri Mar 23 09:33:02 [conn54773] SocketException handling request, closing client connection: 9001 socket exception [2] server [127.0.0.1:53199] 

Fri Mar 23 09:33:02 [conn54774] DBException in process: socket exception

Fri Mar 23 09:33:02 [conn54774] SocketException handling request, closing client connection: 9001 socket exception [2] server [127.0.0.1:53234] 

Fri Mar 23 09:33:03 [conn54792] trying reconnect to nodeA:27123

Fri Mar 23 09:33:03 [conn54792] reconnect nodeA:27123 failed couldn't connect to server nodeA:27123

Fri Mar 23 09:33:05 [conn54795] trying reconnect to nodeA:27123

Fri Mar 23 09:33:05 [conn54795] reconnect nodeA:27123 ok

Fri Mar 23 09:33:12 [WriteBackListener-nodeB:27123] DBClientCursor::init call() failed

Fri Mar 23 09:33:12 [WriteBackListener-nodeB:27123] WriteBackListener exception : DBClientBase::findN: transport error: nodeB:27123 query: { writebacklisten: ObjectId('4f6b5d0f7c830556fb779771') }

Fri Mar 23 09:33:12 [conn54807] Socket recv() errno:104 Connection reset by peer 11.22.33.44:27123

Fri Mar 23 09:33:12 [conn54807] SocketException: remote: 11.22.33.44:27123 error: 9001 socket exception [1] server [11.22.33.44:27123] 

Fri Mar 23 09:33:12 [conn54807] DBClientCursor::init call() failed

Fri Mar 23 09:33:12 [conn54807] trying reconnect to nodeB:27123

Fri Mar 23 09:33:12 [conn54807] reconnect nodeB:27123 ok

Fri Mar 23 09:33:13 [conn54807] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], primary: "nodeB:27123", me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:13 [conn54807] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:13 [conn54808] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], primary: "nodeB:27123", me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:13 [conn54808] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:13 [conn54809] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], primary: "nodeB:27123", me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:13 [conn54809] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:14 [conn54810] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], primary: "nodeB:27123", me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:14 [conn54810] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54811] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54811] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54807] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54807] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54808] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54808] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54809] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:15 [conn54809] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:16 [WriteBackListener-nodeA:27123] WriteBackListener exception : socket exception

Fri Mar 23 09:33:16 [conn54810] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:16 [conn54810] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54811] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54811] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54807] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54807] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54808] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54808] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54809] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:17 [conn54809] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:18 [conn54810] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:18 [conn54810] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:18 [conn54807] Socket recv() errno:104 Connection reset by peer 11.22.33.44:27123

Fri Mar 23 09:33:18 [conn54807] SocketException: remote: 11.22.33.44:27123 error: 9001 socket exception [1] server [11.22.33.44:27123] 

Fri Mar 23 09:33:18 [conn54807] DBClientCursor::init call() failed

Fri Mar 23 09:33:18 [conn54808] Socket recv() errno:104 Connection reset by peer 11.22.33.44:27123

Fri Mar 23 09:33:18 [conn54808] SocketException: remote: 11.22.33.44:27123 error: 9001 socket exception [1] server [11.22.33.44:27123] 

Fri Mar 23 09:33:18 [conn54808] DBClientCursor::init call() failed

Fri Mar 23 09:33:18 [conn54809] Socket recv() errno:104 Connection reset by peer 11.22.33.44:27123

Fri Mar 23 09:33:18 [conn54809] SocketException: remote: 11.22.33.44:27123 error: 9001 socket exception [1] server [11.22.33.44:27123] 

Fri Mar 23 09:33:18 [conn54809] DBClientCursor::init call() failed

Fri Mar 23 09:33:19 [conn54810] Socket recv() errno:104 Connection reset by peer 11.22.33.44:27123

Fri Mar 23 09:33:19 [conn54810] SocketException: remote: 11.22.33.44:27123 error: 9001 socket exception [1] server [11.22.33.44:27123] 

Fri Mar 23 09:33:19 [conn54810] DBClientCursor::init call() failed

Fri Mar 23 09:33:19 [conn54811] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:19 [conn54811] ReplicaSetMonitor::_checkConnection: nodeB:27123 { setName: "repSet1", ismaster: false, secondary: true, hosts: [ "nodeB:27123", "nodeA:27123" ], arbiters: [ "arbiterAB:27321" ], me: "nodeB:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:20 [conn54811] Socket recv() errno:104 Connection reset by peer 11.22.33.44:27123

Fri Mar 23 09:33:20 [conn54811] SocketException: remote: 11.22.33.44:27123 error: 9001 socket exception [1] server [11.22.33.44:27123] 

Fri Mar 23 09:33:20 [conn54811] DBClientCursor::init call() failed

Fri Mar 23 09:33:21 [conn54812] ReplicaSetMonitor::_checkConnection: nodeA:27123 { setName: "repSet1", ismaster: true, secondary: false, hosts: [ "nodeA:27123", "nodeB:27123" ], arbiters: [ "arbiterAB:27321" ], primary: "nodeA:27123", me: "nodeA:27123", maxBsonObjectSize: 16777216, ok: 1.0 }

Fri Mar 23 09:33:31 [Balancer] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:33:31 [Balancer] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:33:31 [Balancer] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:33:31 [Balancer] ~ScopedDbConnection: _conn != null

Fri Mar 23 09:33:31 [Balancer] caught exception while doing balance: error checking clock skew of cluster config1:27123,config2:27123,config3:27123 :: caused by :: 13650 clock skew of the cluster config1:27123,config2:27123,config3:27123 is too far out of bounds to allow distributed locking.

Fri Mar 23 09:34:01 [Balancer] SyncClusterConnection connecting to [config1:27123]

Fri Mar 23 09:34:01 [Balancer] SyncClusterConnection connecting to [config2:27123]

Fri Mar 23 09:34:01 [Balancer] SyncClusterConnection connecting to [config3:27123]

Fri Mar 23 09:34:01 [Balancer] ~ScopedDbConnection: _conn != null

--------------- MONGOS LOG END -----------------

Thanks

V

Пʼятниця, 23 березня 2012 р., 17:31:06 UTC+2 користувач Kristina Chodorow написав:

[V]

Hello  Kristina 

Could you give me some update on this please?

It is really important for us

Thanks a lot

V

Пʼятниця, 23 березня 2012 р., 18:07:52 UTC+2 користувач V написав:

[Kristina Chodorow]

Thanks for the logs.  This looks like an bug in mongos, I've filed a bug you can track here: https://jira.mongodb.org/browse/SERVER-5406.

[V]

Hi Kristina

Could you give me some ETA when this bug supposed to be fixed.

In which version?

thanks

v

Понеділок, 26 березня 2012 р., 18:36:43 UTC+3 користувач Kristina Chodorow написав:

[Kristina Chodorow]

You'll have to watch the bug for that.  I don't know when it will be scheduled for.

[V]

ok thanks

v.

Вівторок, 27 березня 2012 р., 17:21:41 UTC+3 користувач Kristina Chodorow написав: