[SERVER-25057] Initial sync fails on 2d index build Created: 14/Jul/16  Updated: 28/Jul/17  Resolved: 25/Aug/16

Status: Closed
Project: Core Server
Component/s: Geo, Replication
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Judah Schvimer Assignee: Eric Milkie
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Depends
depends on SERVER-25332 Initial sync bootstrap needs to handl... Closed
is depended on by SERVER-24538 Make small_oplog_rs_initsync_static p... Closed
Operating System: ALL
Sprint: Repl 18 (08/05/16), Repl 2016-08-29
Participants:

 Description   

During a patch build of the initial sync passthrough I hit:

[ReplicaSetFixture:job11:initsync] 2016-07-12T22:13:14.147+0000 I REPL     [repl writer worker 0] applying op: { ts: Timestamp 1468361591000|15, t: 1, h: 2542148301098418867, v: 2, op: "i", ns: "test.system.indexes", o: { ns: "test.jstests_multikey_geonear", key: { a: "2d", b: 1.0 }, name: "a_2d_b_1" } }
[ReplicaSetFixture:job11:secondary] 2016-07-12T22:13:13.960+0000 I REPL     [repl writer worker 9] applying op: { ts: Timestamp 1468361593000|84, t: 1, h: -4942554982156627380, v: 2, op: "d", ns: "test.jstests_removec", o: { _id: ObjectId('57856b7855e214ddd20bcd51') } }
[ReplicaSetFixture:job11:initsync] 2016-07-12T22:13:14.151+0000 I INDEX    [repl writer worker 0] build index on: test.jstests_multikey_geonear properties: { v: 1, key: { a: "2d", b: 1.0 }, name: "a_2d_b_1", ns: "test.jstests_multikey_geonear" }
[ReplicaSetFixture:job11:initsync] 2016-07-12T22:13:14.151+0000 I INDEX    [repl writer worker 0] 	 building index using bulk method
[ReplicaSetFixture:job11:secondary] 2016-07-12T22:13:13.964+0000 I REPL     [repl writer worker 13] applying op: { ts: Timestamp 1468361593000|88, t: 1, h: -8359439578022939280, v: 2, op: "d", ns: "test.jstests_removec", o: { _id: ObjectId('57856b7855e214ddd20bcd34') } }
[ReplicaSetFixture:job11:primary] 2016-07-12T22:13:14.161+0000 I NETWORK  [conn47] end connection 10.239.77.218:50990 (5 connections now open)
[ReplicaSetFixture:job11:initsync] 2016-07-12T22:13:14.154+0000 F REPL     [repl writer worker 0] writer worker caught exception:  :: caused by :: 13068 geo field only has 1 element :: caused by :: { _id: 0.0, a: [ { b: 0.0 }, { c: { type: "Point", coordinates: [ 0.0, 0.0 ] } } ] } on: { ts: Timestamp 1468361591000|15, t: 1, h: 2542148301098418867, v: 2, op: "i", ns: "test.system.indexes", o: { ns: "test.jstests_multikey_geonear", key: { a: "2d", b: 1.0 }, name: "a_2d_b_1" } }

When initial sync tries to create the collection, it does not accept this index.

https://evergreen.mongodb.com/task/mongodb_mongo_master_windows_64_2k8_debug_jsCore_small_oplog_rs_initsync_WT_82f742e09ddb00aa4229cfc512fa0b308e7a0eab_16_07_12_21_01_33



 Comments   
Comment by Githook User [ 28/Jul/17 ]

Author:

{'email': 'benety@mongodb.com', 'username': 'benety', 'name': 'Benety Goh'}

Message: Revert "SERVER-25057 convertToCapped uses randomly generated temporary collection name"

This reverts commit ff7f0344468bc7de67f9905a469e2c6f6359e4ac.
Branch: master
https://github.com/mongodb/mongo/commit/8506de95632a873f0cfd88deba887a7de38ecd9d

Comment by Githook User [ 28/Jul/17 ]

Author:

{'email': 'benety@mongodb.com', 'username': 'benety', 'name': 'Benety Goh'}

Message: Revert "SERVER-25057 renameCollection() uses randomly generated temporary collection name"

This reverts commit 3d313292efac3654393d30e0eb439e3df7728171.
Branch: master
https://github.com/mongodb/mongo/commit/ce18f182cfced9bced53c677e97e0a2453f9f9e6

Comment by Githook User [ 28/Jul/17 ]

Author:

{'email': 'benety@mongodb.com', 'username': 'benety', 'name': 'Benety Goh'}

Message: SERVER-25057 renameCollection() uses randomly generated temporary collection name
Branch: master
https://github.com/mongodb/mongo/commit/3d313292efac3654393d30e0eb439e3df7728171

Comment by Githook User [ 28/Jul/17 ]

Author:

{'email': 'benety@mongodb.com', 'username': 'benety', 'name': 'Benety Goh'}

Message: SERVER-25057 convertToCapped uses randomly generated temporary collection name
Branch: master
https://github.com/mongodb/mongo/commit/ff7f0344468bc7de67f9905a469e2c6f6359e4ac

Comment by Eric Milkie [ 08/Aug/16 ]

SERVER-25332 will fix this.

Comment by Judah Schvimer [ 14/Jul/16 ]

This appears to be a race between the collection clone and getting the first op to apply on the initial sync node. Consider the following order of events:

1. Secondary starts fetching operations from primary for its oplog buffer
2. Primary creates a geo index  {a: "2d", b: 1}
3. Primary drops the collection
4. Primary inserts document
{ _id: 0.0, a: [ { b: 0.0 }, { c: { type: "Point", coordinates: [ 0.0, 0.0 ] } } ] }
5. Secondary copies the collection, including document
{ _id: 0.0, a: [ { b: 0.0 }, { c: { type: "Point", coordinates: [ 0.0, 0.0 ] } } ] }
, but not including the geo index {a: "2d", b: 1}
6. Secondary starts to apply its oplog
7. Secondary creates the geo index {a: "2d", b: 1}
8. Secondary gets the above error when indexing { _id: 0.0, a: [ { b: 0.0 }, { c: { type: "Point", coordinates: [ 0.0, 0.0 ] } } ] }.
Later on the secondary will drop this collection and reinsert
{ _id: 0.0, a: [ { b: 0.0 }, { c: { type: "Point", coordinates: [ 0.0, 0.0 ] } } ] }

Comment by Daniel Pasette (Inactive) [ 14/Jul/16 ]

it appears from looking at the test that this could only happen if the drop collection command on L32 of jstests/core/multikey_geonear.js did not replicate or was not registered somehow before the createIndex call was made.

Generated at Thu Feb 08 04:08:09 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.