Skip to content

Instantly share code, notes, and snippets.

@n1mmy

n1mmy/first one

Created September 11, 2013 03:28
Show Gist options
  • Save n1mmy/6519014 to your computer and use it in GitHub Desktop.
Save n1mmy/6519014 to your computer and use it in GitHub Desktop.
Download ZIP
A couple weird handoffs. grep for '\[rs' in logs
Raw
first one
A1:
Thu Sep 5 15:29:32.627 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:29:32.627 [rsHealthPoll] replSet info production-db-a3.meteor.io:27017 is down (or slow to respond): DBClientBase::findN: transport error: production-db-a3.meteor.io:27017 ns: local.$cmd query: { authenticate: 1, nonce: "9c9be1e5e9c0bbe2", user: "__system", key: "f873bc40f50502691bd3c387c744742c" }
Thu Sep 5 15:29:32.627 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state DOWN
Thu Sep 5 15:29:32.629 [rsMgr] not electing self, production-db-a2.meteor.io:27017 would veto with 'production-db-a1.meteor.io:27017 is trying to elect itself but production-db-a3.meteor.io:27017 is already primary and more up-to-date'
Thu Sep 5 15:29:37.503 [rsMgr] not electing self, production-db-a2.meteor.io:27017 would veto with 'production-db-a1.meteor.io:27017 is trying to elect itself but production-db-a3.meteor.io:27017 is already primary and more up-to-date'
Thu Sep 5 15:29:43.508 [rsMgr] not electing self, production-db-a2.meteor.io:27017 would veto with 'production-db-a1.meteor.io:27017 is trying to elect itself but production-db-a3.meteor.io:27017 is already primary and more up-to-date'
Thu Sep 5 15:29:44.631 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:29:50.539 [rsMgr] replSet not trying to elect self as responded yea to someone else recently
Thu Sep 5 15:29:52.359 [rsSyncNotifier] Socket recv() timeout 54.235.126.126:27017
Thu Sep 5 15:29:52.359 [rsBackgroundSync] Socket recv() timeout 54.235.126.126:27017
Thu Sep 5 15:29:52.359 [rsBackgroundSync] SocketException: remote: 54.235.126.126:27017 error: 9001 socket exception [3] server [54.235.126.126:27017]
Thu Sep 5 15:29:52.359 [rsSyncNotifier] SocketException: remote: 54.235.126.126:27017 error: 9001 socket exception [3] server [54.235.126.126:27017]
Thu Sep 5 15:29:52.359 [rsSyncNotifier] replset tracking exception: exception: 10278 dbclient error communicating with server: production-db-a3.meteor.io:27017
Thu Sep 5 15:29:52.359 [rsBackgroundSync] replSet db exception in producer: 10278 dbclient error communicating with server: production-db-a3.meteor.io:27017
Thu Sep 5 15:29:53.297 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is up
Thu Sep 5 15:29:53.297 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state PRIMARY
Thu Sep 5 15:30:02.359 [rsBackgroundSync] replSet syncing to: production-db-a3.meteor.io:27017
Thu Sep 5 15:30:15.527 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:30:15.527 [rsHealthPoll] replSet info production-db-a2.meteor.io:27017 is down (or slow to respond): DBClientBase::findN: transport error: production-db-a2.meteor.io:27017 ns: local.$cmd query: { authenticate: 1, nonce: "1e282ebd0c140c43", user: "__system", key: "fd0ddb32d2fa23402f4e0d9e43c729d9" }
Thu Sep 5 15:30:15.527 [rsHealthPoll] replSet member production-db-a2.meteor.io:27017 is now in state DOWN
Thu Sep 5 15:30:27.345 [rsHealthPoll] replset info production-db-a3.meteor.io:27017 thinks that we are down
Thu Sep 5 15:30:27.531 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:30:29.348 [rsHealthPoll] replset info production-db-a3.meteor.io:27017 thinks that we are down
Thu Sep 5 15:30:29.539 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:30:29.539 [rsHealthPoll] replSet member production-db-a2.meteor.io:27017 is up
Thu Sep 5 15:30:29.539 [rsHealthPoll] replSet member production-db-a2.meteor.io:27017 is now in state SECONDARY
Thu Sep 5 15:30:31.350 [rsHealthPoll] replset info production-db-a3.meteor.io:27017 thinks that we are down
Thu Sep 5 15:30:31.541 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:30:32.137 [rsSyncNotifier] replset setting oplog notifier to production-db-a3.meteor.io:27017
Thu Sep 5 15:30:33.543 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
A2:
Thu Sep 5 15:29:44.495 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:29:44.496 [rsHealthPoll] replSet info production-db-a3.meteor.io:27017 is down (or slow to respond): DBClientBase::findN: transport error: production-db-a3.meteor.io:27017 ns: local.$cmd query: { authenticate: 1, nonce: "57d98818382abc42", user: "__system", key: "9fb741f3067a35fb2feab089a10dfb44" }
Thu Sep 5 15:29:44.496 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state DOWN
Thu Sep 5 15:29:44.927 [rsMgr] replSet info electSelf 5
Thu Sep 5 15:29:52.359 [rsBackgroundSync] Socket recv() timeout 54.235.126.126:27017
Thu Sep 5 15:29:52.359 [rsSyncNotifier] Socket recv() timeout 54.235.126.126:27017
Thu Sep 5 15:29:52.359 [rsBackgroundSync] SocketException: remote: 54.235.126.126:27017 error: 9001 socket exception [3] server [54.235.126.126:27017]
Thu Sep 5 15:29:52.360 [rsSyncNotifier] SocketException: remote: 54.235.126.126:27017 error: 9001 socket exception [3] server [54.235.126.126:27017]
Thu Sep 5 15:29:52.360 [rsSyncNotifier] replset tracking exception: exception: 10278 dbclient error communicating with server: production-db-a3.meteor.io:27017
Thu Sep 5 15:29:52.360 [rsBackgroundSync] replSet db exception in producer: 10278 dbclient error communicating with server: production-db-a3.meteor.io:27017
Thu Sep 5 15:29:53.296 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is up
Thu Sep 5 15:29:53.296 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state PRIMARY
Thu Sep 5 15:30:02.360 [rsMgr] replSet PRIMARY
Thu Sep 5 15:30:02.360 [rsMgr] replSet relinquishing primary state
Thu Sep 5 15:30:02.360 [rsMgr] replSet SECONDARY
Thu Sep 5 15:30:02.360 [rsMgr] replSet closing client sockets after relinquishing primary
Thu Sep 5 15:30:03.302 [rsHealthPoll] replset info production-db-a3.meteor.io:27017 heartbeat failed, retrying
Thu Sep 5 15:30:03.360 [rsBackgroundSync] replSet syncing to: production-db-a3.meteor.io:27017
Thu Sep 5 15:30:19.715 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:30:19.716 [rsHealthPoll] replSet info production-db-a1.meteor.io:27017 is down (or slow to respond): DBClientBase::findN: transport error: production-db-a1.meteor.io:27017 ns: local.$cmd query: { authenticate: 1, nonce: "b92766c8de86e141", user: "__system", key: "ea8c817f8cd05dd4da0c189061b2a103" }
Thu Sep 5 15:30:19.716 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state DOWN
Thu Sep 5 15:30:27.640 [rsSyncNotifier] replset setting oplog notifier to production-db-a3.meteor.io:27017
Thu Sep 5 15:30:27.640 [rsSyncNotifier] Socket flush send() errno:9 Bad file descriptor 54.235.126.126:27017
Thu Sep 5 15:30:27.640 [rsSyncNotifier] caught exception (socket exception [SEND_ERROR] for 54.235.126.126:27017) in destructor (~PiggyBackData)
Thu Sep 5 15:30:31.719 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:30:33.727 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is up
Thu Sep 5 15:30:33.727 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state SECONDARY
A3:
Thu Sep 5 15:29:32.638 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:34.641 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:36.644 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:38.646 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:40.649 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:42.651 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:44.654 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:45.214 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:46.663 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:47.215 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:48.665 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:49.217 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:50.668 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:51.218 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:52.670 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:53.220 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:55.221 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:57.222 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:29:59.224 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:30:01.233 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Thu Sep 5 15:30:26.699 [rsHealthPoll] DBClientCursor::init call() failed
Thu Sep 5 15:30:26.699 [rsHealthPoll] replSet info production-db-a1.meteor.io:27017 is down (or slow to respond): DBClientBase::findN: transport error: production-db-a1.meteor.io:27017 ns: local.$cmd query: { authenticate: 1, nonce: "a728226b31e8bee2", user: "__system", key: "3bb49d76e670f1c79158bb3295d6e8b8" }
Thu Sep 5 15:30:26.702 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state DOWN
Thu Sep 5 15:30:32.136 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is up
Thu Sep 5 15:30:32.136 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state SECONDARY
Raw
second one
A1:
Mon Sep 9 07:24:33.995 [rsHealthPoll] DBClientCursor::init call() failed
Mon Sep 9 07:24:33.995 [rsHealthPoll] replSet info production-db-a3.meteor.io:27017 is down (or slow to respond): DBClientBase::findN: transport error: production-db-a3.meteor.io:27017 ns: local.$cmd query: { authenticate: 1, nonce: "603704ea58ca4394", user: "__system", key: "e867afaafd49b4a42a2df944b8e01e26" }
Mon Sep 9 07:24:33.995 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state DOWN
Mon Sep 9 07:24:34.172 [rsMgr] replSet info electSelf 4
Mon Sep 9 07:24:35.153 [rsMgr] replSet PRIMARY
Mon Sep 9 07:24:40.617 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is up
Mon Sep 9 07:24:40.617 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state PRIMARY
Mon Sep 9 07:24:40.617 [rsMgr] replSet relinquishing primary state
Mon Sep 9 07:24:40.617 [rsMgr] replSet SECONDARY
Mon Sep 9 07:24:40.617 [rsMgr] replSet closing client sockets after relinquishing primary
Mon Sep 9 07:24:41.153 [rsBackgroundSync] replSet syncing to: production-db-a3.meteor.io:27017
Mon Sep 9 07:24:41.335 [rsSyncNotifier] replset setting oplog notifier to production-db-a3.meteor.io:27017
Mon Sep 9 07:24:41.335 [rsSyncNotifier] Socket flush send() errno:9 Bad file descriptor 54.235.125.224:27017
Mon Sep 9 07:24:41.335 [rsSyncNotifier] caught exception (socket exception [SEND_ERROR] for 54.235.125.224:27017) in destructor (~PiggyBackData)
Mon Sep 9 07:24:42.617 [rsHealthPoll] replset info production-db-a3.meteor.io:27017 heartbeat failed, retrying
Mon Sep 9 07:24:45.328 [rsGhostSync] handshake between 5 and production-db-a3.meteor.io:27017
A2:
Mon Sep 9 07:24:25.607 [rsHealthPoll] DBClientCursor::init call() failed
Mon Sep 9 07:24:25.607 [rsHealthPoll] replSet info production-db-a3.meteor.io:27017 is down (or slow to respond): DBClientBase::findN: transport error: production-db-a3.meteor.io:27017 ns: local.$cmd query: { authenticate: 1, nonce: "91b14c5cde7ae8fc", user: "__system", key: "bfcb6f8761662e08e257013abce871e3" }
Mon Sep 9 07:24:25.608 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state DOWN
Mon Sep 9 07:24:25.609 [rsMgr] not electing self, production-db-a1.meteor.io:27017 would veto with 'production-db-a2.meteor.io:27017 is trying to elect itself but production-db-a3.meteor.io:27017 is already primary and more up-to-date'
Mon Sep 9 07:24:31.708 [rsMgr] not electing self, production-db-a1.meteor.io:27017 would veto with 'production-db-a2.meteor.io:27017 is trying to elect itself but production-db-a3.meteor.io:27017 is already primary and more up-to-date'
Mon Sep 9 07:24:35.067 [rsSyncNotifier] Socket recv() timeout 54.235.126.126:27017
Mon Sep 9 07:24:35.067 [rsBackgroundSync] Socket recv() timeout 54.235.126.126:27017
Mon Sep 9 07:24:35.067 [rsGhostSync] Socket recv() timeout 54.235.126.126:27017
Mon Sep 9 07:24:35.067 [rsSyncNotifier] SocketException: remote: 54.235.126.126:27017 error: 9001 socket exception [3] server [54.235.126.126:27017]
Mon Sep 9 07:24:35.068 [rsGhostSync] SocketException: remote: 54.235.126.126:27017 error: 9001 socket exception [3] server [54.235.126.126:27017]
Mon Sep 9 07:24:35.068 [rsBackgroundSync] SocketException: remote: 54.235.126.126:27017 error: 9001 socket exception [3] server [54.235.126.126:27017]
Mon Sep 9 07:24:35.068 [rsSyncNotifier] replset tracking exception: exception: 10278 dbclient error communicating with server: production-db-a3.meteor.io:27017
Mon Sep 9 07:24:35.068 [rsBackgroundSync] replSet db exception in producer: 10278 dbclient error communicating with server: production-db-a3.meteor.io:27017
Mon Sep 9 07:24:35.710 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state PRIMARY
Mon Sep 9 07:24:37.607 [rsHealthPoll] DBClientCursor::init call() failed
Mon Sep 9 07:24:37.607 [rsHealthPoll] replset info production-db-a3.meteor.io:27017 heartbeat failed, retrying
Mon Sep 9 07:24:38.607 [rsHealthPoll] DBClientCursor::init call() failed
Mon Sep 9 07:24:40.620 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is up
Mon Sep 9 07:24:40.620 [rsHealthPoll] replSet member production-db-a3.meteor.io:27017 is now in state PRIMARY
Mon Sep 9 07:24:40.620 [rsMgr] replSet info two primaries (transiently)
Mon Sep 9 07:24:41.715 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state SECONDARY
Mon Sep 9 07:24:45.068 [rsBackgroundSync] replSet syncing to: production-db-a1.meteor.io:27017
Mon Sep 9 07:24:45.238 [rsSyncNotifier] replset setting oplog notifier to production-db-a1.meteor.io:27017
A3:
Mon Sep 9 07:24:25.734 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:27.740 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:29.741 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:31.743 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:33.744 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:35.464 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:35.464 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state PRIMARY
Mon Sep 9 07:24:35.745 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:37.467 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:37.747 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:39.470 [rsHealthPoll] replset info production-db-a1.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:39.748 [rsHealthPoll] replset info production-db-a2.meteor.io:27017 thinks that we are down
Mon Sep 9 07:24:41.472 [rsHealthPoll] replSet member production-db-a1.meteor.io:27017 is now in state SECONDARY
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment