MongoDB Initisync fails

Anup_D1 · 2024-08-05T15:25:54.220Z

Hello Team,
Trying to set up a new secondary in a replica set, which is currently Primary, secondary and arbiter. Now trying to add a new secondary, but unable to add it and is failing with below error -

Current mongo version is 4.2.3

2024-08-04T09:38:07.085+0000 I  INITSYNC [replication-6] CollectionCloner ns:DB.attempt finished cloning with status: Location16465: Error querying collection 'DB.attempt :: caused by :: recv failed while exhausting cursor
2024-08-04T09:38:07.115+0000 I  INDEX    [replication-6] Did not timestamp index abort write.
2024-08-04T09:38:07.158+0000 I  NETWORK  [listener] connection accepted from xx.xxx.xxx.xxx:8594 #116096 (58 connections now open)
2024-08-04T09:38:07.159+0000 I  NETWORK  [conn116096] received client metadata from xx.xxx.xxx.xxx:8594 conn116096: { driver: { name: "mongo-java-driver|sync|spring-data", version: "4.8.2" }, os: { type: "Linux", name: "Linux", architecture: "amd64", version: "5.14.0-362.18.1.el9_3.0.1.x86_64" }, platform: "Java/Oracle Corporation/21+35-LTS-2513" }
2024-08-04T09:38:07.246+0000 I  INDEX    [replication-6] Did not timestamp index abort write.
2024-08-04T09:38:07.285+0000 I  NETWORK  [listener] connection accepted from xx.xxx.xxx.xxx:13395 #116097 (59 connections now open)
2024-08-04T09:38:07.285+0000 I  NETWORK  [conn116097] received client metadata from xx.xxx.xxx.xxx:13395 conn116097: { driver: { name: "mongo-java-driver|sync|spring-data", version: "4.8.2" }, os: { type: "Linux", name: "Linux", architecture: "amd64", version: "5.14.0-362.18.1.el9_3.0.1.x86_64" }, platform: "Java/Oracle Corporation/21+35-LTS-2513" }
2024-08-04T09:38:07.287+0000 E  INITSYNC [replication-6] collection clone for 'DB.attempt' failed due to Location16465: Error cloning collection 'DB.attempt' :: caused by :: Error querying collection 'DB.attempt :: caused by :: recv failed while exhausting cursor
2024-08-04T09:38:07.287+0000 W  INITSYNC [replication-6] database 'DB' (100 of 227) clone failed due to InitialSyncFailure: Location16465: Error cloning collection 'DB.attempt' :: caused by :: Error querying collection 'DB.attempt :: caused by :: recv failed while exhausting cursor
2024-08-04T09:38:07.287+0000 I  INITSYNC [replication-6] Finished cloning data: InitialSyncFailure: Location16465: Error cloning collection 'DB.attempt' :: caused by :: Error querying collection 'DB.attempt :: caused by :: recv failed while exhausting cursor. Beginning oplog replay.
2024-08-04T09:38:07.287+0000 I  INITSYNC [replication-7] Finished fetching oplog during initial sync: CallbackCanceled: error in fetcher batch callback: oplog fetcher is shutting down. Last fetched optime: { ts: Timestamp(1722764286, 36), t: 180 }
2024-08-04T09:38:07.287+0000 I  INITSYNC [replication-7] Initial sync attempt finishing up.

Any quick help with this would be appreciated.

Anup_D1 · 2024-08-06T05:43:58.806Z

Hello,
Quick help on the topic would be appreciated.

Anup_D1 · 2024-08-06T15:03:15.057Z

some more logs in case if it could help -

2024-08-06T14:55:55.313+0000 I NETWORK [conn296623] end connection 10.99.32.44:51954 (53 connections now open)
2024-08-06T14:55:55.316+0000 E INITSYNC [replication-11] collection clone for ‘SPCTNT27Site.attempt’ failed due to Location16465: Error cloning collection ‘SPCTNT27Site.attempt’ :: caused by :: Error querying collection 'SPCTNT27Site.attempt :: caused by :: recv failed while exhausting cursor
2024-08-06T14:55:55.316+0000 W INITSYNC [replication-11] database ‘SPCTNT27Site’ (188 of 227) clone failed due to InitialSyncFailure: Location16465: Error cloning collection ‘SPCTNT27Site.attempt’ :: caused by :: Error querying collection 'SPCTNT27Site.attempt :: caused by :: recv failed while exhausting cursor
2024-08-06T14:55:55.316+0000 I INITSYNC [replication-11] Finished cloning data: InitialSyncFailure: Location16465: Error cloning collection ‘SPCTNT27Site.attempt’ :: caused by :: Error querying collection 'SPCTNT27Site.attempt :: caused by :: recv failed while exhausting cursor. Beginning oplog replay.
2024-08-06T14:55:55.317+0000 I INITSYNC [replication-9] Finished fetching oplog during initial sync: CallbackCanceled: error in fetcher batch callback: oplog fetcher is shutting down. Last fetched optime: { ts: Timestamp(1722956153, 11), t: 182 }
2024-08-06T14:55:55.317+0000 I INITSYNC [replication-9] Initial sync attempt finishing up.
2024-08-06T14:55:55.351+0000 I INITSYNC [replication-9] warning: log line attempted (2321kB) over max size (10kB), printing beginning and end … Initial Sync Attempt Statistics: { failedInitialSyncAttempts: 2, maxFailedInitialSyncAttempts: 10, initialSyncStart: new Date(1722896814658), initialSyncAttempts: [ { durationMillis: 634680, status: “InitialSyncFailure: error cloning databases :: caused by :: HostUnreachable: Error cloning collection ‘EU1PRD0005.digest_new_ideas_person’ :: caused b…”, syncSource: “10.99.48.56:19000” }, { durationMillis: 22487021, status: “InitialSyncFailure: error cloning databases :: caused by :: Location16465: Error cloning collection ‘EU2PRD0068.message_archive’ :: caused by :: Error…”, syncSource: “10.99.48.57:19000” } ], fetchedMissingDocs: 0, appliedOps: 0, initialSyncOplogStart: Timestamp(1722921527, 179), initialSyncOplogFetchingStart: Timestamp(1722921524, 16), databases: { databasesCloned: 187, admin: { collections: 32, clonedCollections: 32, start: new Date(1722921529125), end: new Date(1722921538450), elapsedMillis: 9325, admin.smartlist_active_members: { documentsToCopy: 0, documentsCopied: 0, indexes: 2, fetchedBatches: 0, start: new Date(1722921529159), end: new Date(1722921529416), elapsedMillis: 257, receivedBatches: 0 }, admin.rest_notify_logs: { documentsToCopy: 0, documentsCopied: 0, indexes: 6, fetchedBatches: 0, start: new Date(1722921529416), end: new Date(1722921529724), elapsedMillis: 308, receivedBatches: 0 }, admin.searchhistory: { documentsToCopy: 0, documentsCopied: 0, indexes: 3, fetchedBatches: 0, start: new Date(1722921529724), end: new Date(1722921529941), elapsedMillis: 217, receivedBatches: 0 }, admin.digest_queue_log: { documentsToCopy: 0, documentsCopied: 0, indexes: 2, fetchedBatches: 0, start: new Date(1722921529941), end: new Date(1722921530139), elapsedMillis: 198, receivedBatches: 0 }, admin.tincanStatement: { documentsToCopy: 0, documentsCopied: 0, indexes: 11, fetchedBatches: 0, start: new Date(1722921530139), end: new Date(1722921530649), elapsedMillis: 510, receivedBatches: 0 }, admin.smartlist: { documentsToCopy: 0, documentsCopied: 0, indexes: 2, fetchedBatches: 0, start: new Date(1722921530649), end: new Date(1722921530820), elapsedMillis: 171, receivedBatches: 0 }, admin.REGISTRATIONINFO: { documentsToCopy: 0, documentsCopied: 0, indexes: 2, fetchedBatches: 0, start: new Date(1722921530819), end: new Date(1722921531056), elapsedMillis: 237, receivedBatches: 0 }, admin.componentmapping: { documentsToCopy: 26, documentsCopied: 26, indexes: 1, fetchedBatches: 1, start: new Date(1722921531056), end: new Date(1722921531232), elapsedMillis: 176, receivedBatches: 1 }, admin.system.users: { documentsToCopy: 1, documentsCopied: 1, indexes: 2, fetchedBatches: 1, start: new Date(1722921531232), end: new Date(1722921531496), elapsedMillis: 264, receivedBatches: 1 }, admin.smf_job: { documentsToCopy: 0, documentsCopied: 0, indexes: 9, fetchedBatches: 0, start: new Date(1722921531496), end: new Date(1722921531866), elapsedMillis: 370, receivedBatches: 0 }, admin.digest_queue: { documentsToCopy: 0, documentsCopied: 0, indexes: 2, fetchedBatches: 0, start: new Date(1722921531866), end: new Date(1722921532094), elapsedMillis: 228, receivedBatches: 0 }, admin.patch_manifest: { documentsToCopy: 33, documentsCopied: 33, indexes: 1, fetchedBatches: 1, start: new Date(1722921532094), end: new Date(1722921532298), elapsedMillis: 204, receivedBatches: 1 }, admin.smartlist_audit: { documentsToCopy: 0, documentsCopied: 0, indexes: 2, fetche … atches: 0 }, SPCTNT27Site.digest_top_viewed: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.alerts: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.profile_sync_queue: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.launch: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.email_recipient_summary: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.api_filter_policy: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.smartlist: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.compattrs: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.recruiting_configuration: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 }, SPCTNT27Site.pr_delay_requests: { documentsToCopy: 0, documentsCopied: 0, indexes: 0, fetchedBatches: 0, receivedBatches: 0 } }, SPCTNT28Site: { collections: 0, clonedCollections: 0 }, SPCTNT32Site: { collections: 0, clonedCollections: 0 }, SPCTNT33Site: { collections: 0, clonedCollections: 0 }, SPCTNT34Site: { collections: 0, clonedCollections: 0 }, SPCTNT356Site: { collections: 0, clonedCollections: 0 }, SPCTNT35Site: { collections: 0, clonedCollections: 0 }, SPCTNT36Site: { collections: 0, clonedCollections: 0 }, SPCTNT40Site: { collections: 0, clonedCollections: 0 }, SPCTNT46Site: { collections: 0, clonedCollections: 0 }, SPCTNT47Site: { collections: 0, clonedCollections: 0 }, SPCTNT48Site: { collections: 0, clonedCollections: 0 }, SPCTNT50Site: { collections: 0, clonedCollections: 0 }, SPCTNT51Site: { collections: 0, clonedCollections: 0 }, SPCTNT53Site: { collections: 0, clonedCollections: 0 }, SPCTNT57Site: { collections: 0, clonedCollections: 0 }, SPCTNT59Site: { collections: 0, clonedCollections: 0 }, SPCTNT60Site: { collections: 0, clonedCollections: 0 }, SPCTNT61Site: { collections: 0, clonedCollections: 0 }, SPCTNT62Site: { collections: 0, clonedCollections: 0 }, SPCTNT63Site: { collections: 0, clonedCollections: 0 }, SPCTNT65Site: { collections: 0, clonedCollections: 0 }, SPCTNT66Site: { collections: 0, clonedCollections: 0 }, SPCTNT67Site: { collections: 0, clonedCollections: 0 }, SPCTNT69Site: { collections: 0, clonedCollections: 0 }, SPCTNT7Site: { collections: 0, clonedCollections: 0 }, SPCTNT88Site: { collections: 0, clonedCollections: 0 }, SPCTNT8Site: { collections: 0, clonedCollections: 0 }, SPCTNT90Site: { collections: 0, clonedCollections: 0 }, SPCTNT92Site: { collections: 0, clonedCollections: 0 }, SPCTNT93Site: { collections: 0, clonedCollections: 0 }, SPCTNT9Site: { collections: 0, clonedCollections: 0 }, SPCTNTPMSite: { collections: 0, clonedCollections: 0 }, Saba: { collections: 0, clonedCollections: 0 }, SabaSite: { collections: 0, clonedCollections: 0 }, TNBTNT102: { collections: 0, clonedCollections: 0 }, TNBTNT111: { collections: 0, clonedCollections: 0 }, BaselineSite: { collections: 0, clonedCollections: 0 }, config: { collections: 0, clonedCollections: 0 }, test: { collections: 0, clonedCollections: 0 } } }
2024-08-06T14:55:55.351+0000 E INITSYNC [replication-9] Initial sync attempt failed – attempts left: 7 cause: InitialSyncFailure: error cloning databases :: caused by :: Location16465: Error cloning collection ‘SPCTNT27Site.attempt’ :: caused by :: Error querying collection 'SPCTNT27Site.attempt :: caused by :: recv failed while exhausting cursor