[SERVER-10212] prefix_shard_key.js failed on V2.4 Linux 64-bit Created: 15/Jul/13  Updated: 10/Dec/14  Resolved: 25/Jul/13

Status: Closed
Project: Core Server
Component/s: Testing Infrastructure
Affects Version/s: 2.4.5
Fix Version/s: None

Type: Bug Priority: Minor - P4
Reporter: Matt Kangas Assignee: Greg Studer
Resolution: Done Votes: 0
Labels: buildbot
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

V2.4 Linux 64-bit Build #143


Operating System: ALL
Participants:

 Description   

Intermittent. Next build succeeded, didn't find other examples within the last 50 builds.

V2.4 Linux 64-bit Build #143 July 14 (rev 22df6cbb2b)

http://buildbot.mongodb.org/builders/V2.4%20Linux%2064-bit/builds/143/steps/test_10/logs/stdio
http://buildlogs.mongodb.org/V2.4%20Linux%2064-bit/builds/143/test/sharding/prefix_shard_key.js

 m30001| Sun Jul 14 06:46:12.318 [conn5] moveChunk migrate commit accepted by TO-shard: { active: true, ns: "test.foo", from: "localhost:30001", min: { num: MinKey }, max: { num: 50.0 }, shardKeyPattern: { num: 1.0 }, state: "done", counts: { cloned: 50, clonedBytes: 6555850, catchup: 0, steady: 0 }, ok: 1.0 }
 m30001| Sun Jul 14 06:46:12.319 [conn5] moveChunk updating self version to: 2|1||51e281730fce19c3644bc9c9 through { num: 50.0 } -> { num: MaxKey } for collection 'test.foo'
{ "millis" : 316, "ok" : 1 }
 m30001| Sun Jul 14 06:46:12.322 [conn5] about to log metadata event: { _id: "ip-10-2-29-40-2013-07-14T10:46:12-51e2817415c2ea3fbaaabf9d", server: "ip-10-2-29-40", clientAddr: "127.0.0.1:56260", time: new Date(1373798772322), what: "moveChunk.commit", ns: "test.foo", details: { min: { num: MinKey }, max: { num: 50.0 }, from: "shard0001", to: "shard0000" } }
 m30001| Sun Jul 14 06:46:12.322 [conn5] MigrateFromStatus::done About to acquire global write lock to exit critical section
 m30001| Sun Jul 14 06:46:12.322 [conn5] MigrateFromStatus::done Global lock acquired
 m30001| Sun Jul 14 06:46:12.322 [conn5] doing delete inline for cleanup of chunk data
 m30001| Sun Jul 14 06:46:12.322 [conn5] moveChunk starting delete for: test.foo from { num: MinKey } -> { num: 50.0 }
 m30001| Sun Jul 14 06:46:12.324 [conn5] moveChunk deleted 50 documents for test.foo from { num: MinKey } -> { num: 50.0 }
 m30001| Sun Jul 14 06:46:12.324 [conn5] MigrateFromStatus::done About to acquire global write lock to exit critical section
 m30001| Sun Jul 14 06:46:12.324 [conn5] MigrateFromStatus::done Global lock acquired
 m30001| Sun Jul 14 06:46:12.325 [conn5] distributed lock 'test.foo/ip-10-2-29-40:30001:1373798772:38842760' unlocked. 
 m30001| Sun Jul 14 06:46:12.325 [conn5] about to log metadata event: { _id: "ip-10-2-29-40-2013-07-14T10:46:12-51e2817415c2ea3fbaaabf9e", server: "ip-10-2-29-40", clientAddr: "127.0.0.1:56260", time: new Date(1373798772325), what: "moveChunk.from", ns: "test.foo", details: { min: { num: MinKey }, max: { num: 50.0 }, step1 of 6: 0, step2 of 6: 1, step3 of 6: 0, step4 of 6: 293, step5 of 6: 18, step6 of 6: 1 } }
 m30001| Sun Jul 14 06:46:12.325 [conn5] command admin.$cmd command: { moveChunk: "test.foo", from: "localhost:30001", to: "localhost:30000", fromShard: "shard0001", toShard: "shard0000", min: { num: MinKey }, max: { num: 50.0 }, maxChunkSizeBytes: 52428800, shardId: "test.foo-num_MinKey", configdb: "localhost:30000", secondaryThrottle: false, waitForDelete: true } ntoreturn:1 keyUpdates:0 locks(micros) W:14 r:101 w:1460 reslen:37 315ms
error preparing documents for insert :: caused by :: tried to insert object with no valid shard key for { num: 1.0 } : { _id: ObjectId('51e281740b244f8b5ae91619'), num: [ 1.0, 2.0 ], x: 1.0 }
{
	"cause" : {
		"ok" : 0,
		"errmsg" : "can't find index in storeCurrentLocs :: caused by :: "
	},
	"ok" : 0,
	"errmsg" : "move failed"
}
{
	"cause" : {
		"cause" : {
			"ok" : 0,
			"errmsg" : "migrate already in progress"
		},
		"ok" : 0,
		"errmsg" : "moveChunk failed to engage TO-shard in the data transfer: migrate already in progress"
	},
	"ok" : 0,
	"errmsg" : "move failed"
}
assert: [1] != [0] are not equal : moveChunk failed after rebuilding index
Error: Printing Stack Trace
    at printStackTrace (src/mongo/shell/utils.js:37:15)
    at doassert (src/mongo/shell/assert.js:6:5)
    at Function.assert.eq (src/mongo/shell/assert.js:32:5)
    at /mntfast/data/slave/Linux_64bit_V2.4/mongo/jstests/sharding/prefix_shard_key.js:103:8
Sun Jul 14 06:46:12.351 JavaScript execution failed: [1] != [0] are not equal : moveChunk failed after rebuilding index at src/mongo/shell/assert.js:L7
failed to load: /mntfast/data/slave/Linux_64bit_V2.4/mongo/jstests/sharding/prefix_shard_key.js



 Comments   
Comment by Matt Kangas [ 25/Jul/13 ]

10 days (10 builds) have passed and this hasn't recurred. Closing until we have more evidence.

Comment by Greg Studer [ 15/Jul/13 ]

First failure is expected and part of test, second failure is because the migration hasn't yet aborted on the TO-side. Unfortunately, when the TO-side picks up this failure is undefined w.r.t. the FROM-side, which is what returns to the shell.

Looks like VM timing may also be a trigger here, the ordering of log entries is kind of weird.

Generated at Thu Feb 08 03:22:35 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.