scalien/scaliendb — Issue #320: ShardMigrationWriter sometimes ASSERTs after having written all chunks
Author: agazso
Created: 2011-11-05 09:54:10+00:00
State: open

2011-11-05 10:49:32.964: [192.168.137.235:41453] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42074] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42042] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41677] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41477] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42114] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42014] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41958] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42030] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42090] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42006] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41585] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41873] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41553] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42174] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41917] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41601] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41401] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42078] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41777] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41745] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41753] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41501] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41970] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42022] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41733] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41505] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41589] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41581] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41533] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41966] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41405] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41729] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42034] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:42010] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41397] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41465] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41461] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41998] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41905] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41605] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41809] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41597] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41861] Connection deleted
2011-11-05 10:49:32.964: [192.168.137.235:41665] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41445] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41821] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:42102] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:42066] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41541] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41637] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41493] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41657] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41781] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:42106] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41765] Connection deleted
2011-11-05 10:49:32.980: [192.168.137.235:41457] Connection deleted
2011-11-05 10:49:32.980: numOps: 170
2011-11-05 10:49:36.214: Write last error = 10061
2011-11-05 10:49:39.230: ShardMigrationWriter::Begin() nodeID = 103
2011-11-05 10:49:39.230: ShardMigrationWriter::Begin() quorumID = 2
2011-11-05 10:49:39.230: ShardMigrationWriter::Begin() srcShardID = 24310
2011-11-05 10:49:39.230: ShardMigrationWriter::Begin() dstShardID = 24311
2011-11-05 10:49:39.230: Migrating shard 24310 into quorum 2 as shard 24311 (sen
ding)
2011-11-05 10:49:39.230: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:39.230: ShardMigrationWriter sending BEGIN
2011-11-05 10:49:39.292: NextBunch chunkID = 7943
2011-11-05 10:49:39.292: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:39.402: Pushing memo chunk1
2011-11-05 10:49:39.402: Serializing chunk 7943 in memory...
2011-11-05 10:49:39.480: NextBunch chunkID = 7943
2011-11-05 10:49:39.480: IOProcessor callback elapsed time: 188
2011-11-05 10:49:39.480: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:39.636: NextBunch chunkID = 7943
2011-11-05 10:49:39.652: IOProcessor callback elapsed time: 156
2011-11-05 10:49:39.808: Softclock diff: 141
2011-11-05 10:49:39.824: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:39.933: NextBunch chunkID = 7943
2011-11-05 10:49:39.949: IOProcessor callback elapsed time: 109
2011-11-05 10:49:40.214: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:40.308: NextBunch chunkID = 7943
2011-11-05 10:49:40.371: Done serializing, elapsed: 969
2011-11-05 10:49:40.371: Deleting in-memory chunk 7943
2011-11-05 10:49:40.449: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:40.496: NextBunch chunkID = 7943
2011-11-05 10:49:40.496: NextBunch chunkID = 7943
2011-11-05 10:49:40.511: NextBunch chunkID = 7943
2011-11-05 10:49:40.511: NextBunch chunkID = 7943
2011-11-05 10:49:40.511: NextBunch chunkID = 7943
2011-11-05 10:49:40.777: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:40.777: NextBunch chunkID = 7943
2011-11-05 10:49:40.777: NextBunch chunkID = 7943
2011-11-05 10:49:40.777: NextBunch chunkID = 7943
2011-11-05 10:49:40.792: NextBunch chunkID = 7943
2011-11-05 10:49:40.792: NextBunch chunkID = 7943
2011-11-05 10:49:40.824: NextBunch chunkID = 7943
2011-11-05 10:49:40.824: NextBunch chunkID = 7943
2011-11-05 10:49:40.839: NextBunch chunkID = 7943
2011-11-05 10:49:40.839: NextBunch chunkID = 7943
2011-11-05 10:49:40.855: NextBunch chunkID = 7943
2011-11-05 10:49:40.871: NextBunch chunkID = 7943
2011-11-05 10:49:40.871: NextBunch chunkID = 7943
2011-11-05 10:49:40.871: NextBunch chunkID = 7943
2011-11-05 10:49:40.871: NextBunch chunkID = 7943
2011-11-05 10:49:40.886: NextBunch chunkID = 7943
2011-11-05 10:49:40.886: NextBunch chunkID = 7943
2011-11-05 10:49:40.917: NextBunch chunkID = 7943
2011-11-05 10:49:40.917: IOProcessor callback elapsed time: 140
2011-11-05 10:49:40.917: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:40.917: NextBunch chunkID = 7943
2011-11-05 10:49:40.933: NextBunch chunkID = 7943
2011-11-05 10:49:40.933: NextBunch chunkID = 7943
2011-11-05 10:49:40.933: NextBunch chunkID = 7943
2011-11-05 10:49:40.933: NextBunch chunkID = 7943
2011-11-05 10:49:40.964: NextBunch chunkID = 7943
2011-11-05 10:49:40.964: NextBunch chunkID = 7943
2011-11-05 10:49:40.980: NextBunch chunkID = 7943
2011-11-05 10:49:40.980: NextBunch chunkID = 7943
2011-11-05 10:49:40.980: NextBunch chunkID = 7943
2011-11-05 10:49:40.996: NextBunch chunkID = 7943
2011-11-05 10:49:40.996: NextBunch chunkID = 7943
2011-11-05 10:49:40.996: NextBunch chunkID = 7943
2011-11-05 10:49:40.996: NextBunch chunkID = 7943
2011-11-05 10:49:41.027: NextBunch chunkID = 7943
2011-11-05 10:49:41.027: NextBunch chunkID = 7943
2011-11-05 10:49:41.042: NextBunch chunkID = 7943
2011-11-05 10:49:41.042: NextBunch chunkID = 7943
2011-11-05 10:49:41.042: IOProcessor callback elapsed time: 125
2011-11-05 10:49:41.058: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:41.058: NextBunch chunkID = 7943
2011-11-05 10:49:41.074: NextBunch chunkID = 7943
2011-11-05 10:49:41.074: NextBunch chunkID = 7943
2011-11-05 10:49:41.089: NextBunch chunkID = 7943
2011-11-05 10:49:41.089: NextBunch chunkID = 7943
2011-11-05 10:49:41.105: NextBunch chunkID = 7943
2011-11-05 10:49:41.105: NextBunch chunkID = 7943
2011-11-05 10:49:41.121: NextBunch chunkID = 7943
2011-11-05 10:49:41.121: NextBunch chunkID = 7943
2011-11-05 10:49:41.136: NextBunch chunkID = 7943
2011-11-05 10:49:41.152: NextBunch chunkID = 7943
2011-11-05 10:49:41.152: NextBunch chunkID = 7943
2011-11-05 10:49:41.152: NextBunch chunkID = 7943
2011-11-05 10:49:41.152: NextBunch chunkID = 7943
2011-11-05 10:49:41.167: NextBunch chunkID = 7943
2011-11-05 10:49:41.167: NextBunch chunkID = 7943
2011-11-05 10:49:41.167: NextBunch chunkID = 7943
2011-11-05 10:49:41.199: IOProcessor callback elapsed time: 141
2011-11-05 10:49:41.199: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:41.199: NextBunch chunkID = 7943
2011-11-05 10:49:41.230: NextBunch chunkID = 7943
2011-11-05 10:49:41.230: NextBunch chunkID = 7943
2011-11-05 10:49:41.246: NextBunch chunkID = 7943
2011-11-05 10:49:41.246: NextBunch chunkID = 7943
2011-11-05 10:49:41.261: NextBunch chunkID = 7943
2011-11-05 10:49:41.261: NextBunch chunkID = 7943
2011-11-05 10:49:41.277: NextBunch chunkID = 7943
2011-11-05 10:49:41.292: NextBunch chunkID = 7943
2011-11-05 10:49:41.292: NextBunch chunkID = 7943
2011-11-05 10:49:41.308: NextBunch chunkID = 7943
2011-11-05 10:49:41.308: NextBunch chunkID = 7943
2011-11-05 10:49:41.308: NextBunch chunkID = 7943
2011-11-05 10:49:41.308: NextBunch chunkID = 7943
2011-11-05 10:49:41.324: NextBunch chunkID = 7943
2011-11-05 10:49:41.324: NextBunch chunkID = 7943
2011-11-05 10:49:41.355: NextBunch chunkID = 7943
2011-11-05 10:49:41.355: NextBunch chunkID = 7943
2011-11-05 10:49:41.355: IOProcessor callback elapsed time: 156
2011-11-05 10:49:41.371: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:41.371: NextBunch chunkID = 7943
2011-11-05 10:49:41.371: NextBunch chunkID = 7943
2011-11-05 10:49:41.371: NextBunch chunkID = 7943
2011-11-05 10:49:41.402: NextBunch chunkID = 7943
2011-11-05 10:49:41.402: NextBunch chunkID = 7943
2011-11-05 10:49:41.417: NextBunch chunkID = 7943
2011-11-05 10:49:41.417: NextBunch chunkID = 7943
2011-11-05 10:49:41.433: NextBunch chunkID = 7943
2011-11-05 10:49:41.433: NextBunch chunkID = 7943
2011-11-05 10:49:41.449: NextBunch chunkID = 7943
2011-11-05 10:49:41.449: NextBunch chunkID = 7943
2011-11-05 10:49:41.464: NextBunch chunkID = 7943
2011-11-05 10:49:41.464: NextBunch chunkID = 7943
2011-11-05 10:49:41.480: NextBunch chunkID = 7943
2011-11-05 10:49:41.480: NextBunch chunkID = 7943
2011-11-05 10:49:41.480: NextBunch chunkID = 7943
2011-11-05 10:49:41.496: NextBunch chunkID = 7943
2011-11-05 10:49:41.511: IOProcessor callback elapsed time: 140
2011-11-05 10:49:41.511: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:41.511: NextBunch chunkID = 7943
2011-11-05 10:49:41.527: NextBunch chunkID = 7943
2011-11-05 10:49:41.542: NextBunch chunkID = 7943
2011-11-05 10:49:41.542: NextBunch chunkID = 7943
2011-11-05 10:49:41.558: NextBunch chunkID = 7943
2011-11-05 10:49:41.589: NextBunch chunkID = 7943
2011-11-05 10:49:41.589: NextBunch chunkID = 7943
2011-11-05 10:49:41.589: NextBunch chunkID = 7943
2011-11-05 10:49:41.605: NextBunch chunkID = 7943
2011-11-05 10:49:41.621: NextBunch chunkID = 7943
2011-11-05 10:49:41.636: NextBunch chunkID = 7943
2011-11-05 10:49:41.652: NextBunch chunkID = 7943
2011-11-05 10:49:41.667: NextBunch chunkID = 7943
2011-11-05 10:49:41.667: NextBunch chunkID = 7943
2011-11-05 10:49:41.699: NextBunch chunkID = 7943
2011-11-05 10:49:41.699: NextBunch chunkID = 7943
2011-11-05 10:49:41.714: NextBunch chunkID = 7943
2011-11-05 10:49:41.730: NextBunch chunkID = 7943
2011-11-05 10:49:41.730: IOProcessor callback elapsed time: 219
2011-11-05 10:49:41.730: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:41.746: NextBunch chunkID = 7943
2011-11-05 10:49:41.761: NextBunch chunkID = 7943
2011-11-05 10:49:41.761: NextBunch chunkID = 7943
2011-11-05 10:49:41.777: NextBunch chunkID = 7943
2011-11-05 10:49:41.792: NextBunch chunkID = 7943
2011-11-05 10:49:41.792: NextBunch chunkID = 7943
2011-11-05 10:49:41.808: NextBunch chunkID = 7943
2011-11-05 10:49:41.824: NextBunch chunkID = 7943
2011-11-05 10:49:41.839: NextBunch chunkID = 7943
2011-11-05 10:49:41.839: NextBunch chunkID = 7943
2011-11-05 10:49:41.855: NextBunch chunkID = 7943
2011-11-05 10:49:41.871: NextBunch chunkID = 7943
2011-11-05 10:49:41.871: NextBunch chunkID = 7943
2011-11-05 10:49:41.886: NextBunch chunkID = 7943
2011-11-05 10:49:41.902: NextBunch chunkID = 7943
2011-11-05 10:49:41.902: NextBunch chunkID = 7943
2011-11-05 10:49:41.917: NextBunch chunkID = 7943
2011-11-05 10:49:41.917: NextBunch chunkID = 7943
2011-11-05 10:49:41.917: IOProcessor callback elapsed time: 187
2011-11-05 10:49:41.933: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:41.933: NextBunch chunkID = 7943
2011-11-05 10:49:41.933: NextBunch chunkID = 7943
2011-11-05 10:49:41.949: NextBunch chunkID = 7943
2011-11-05 10:49:41.949: NextBunch chunkID = 7943
2011-11-05 10:49:41.964: NextBunch chunkID = 7943
2011-11-05 10:49:41.964: NextBunch chunkID = 7943
2011-11-05 10:49:41.980: NextBunch chunkID = 7943
2011-11-05 10:49:41.980: NextBunch chunkID = 7943
2011-11-05 10:49:41.980: NextBunch chunkID = 7943
2011-11-05 10:49:41.996: NextBunch chunkID = 7943
2011-11-05 10:49:41.996: NextBunch chunkID = 7943
2011-11-05 10:49:42.011: NextBunch chunkID = 7943
2011-11-05 10:49:42.011: NextBunch chunkID = 7943
2011-11-05 10:49:42.011: NextBunch chunkID = 7943
2011-11-05 10:49:42.027: NextBunch chunkID = 7943
2011-11-05 10:49:42.027: NextBunch chunkID = 7943
2011-11-05 10:49:42.042: NextBunch chunkID = 7943
2011-11-05 10:49:42.042: IOProcessor callback elapsed time: 109
2011-11-05 10:49:42.042: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:42.042: NextBunch chunkID = 7943
2011-11-05 10:49:42.058: NextBunch chunkID = 7943
2011-11-05 10:49:42.058: NextBunch chunkID = 7943
2011-11-05 10:49:42.074: NextBunch chunkID = 7943
2011-11-05 10:49:42.074: NextBunch chunkID = 7943
2011-11-05 10:49:42.074: NextBunch chunkID = 7943
2011-11-05 10:49:42.089: NextBunch chunkID = 7943
2011-11-05 10:49:42.089: NextBunch chunkID = 7943
2011-11-05 10:49:42.105: NextBunch chunkID = 7943
2011-11-05 10:49:42.105: NextBunch chunkID = 7943
2011-11-05 10:49:42.105: NextBunch chunkID = 7943
2011-11-05 10:49:42.121: NextBunch chunkID = 7943
2011-11-05 10:49:42.121: NextBunch chunkID = 7943
2011-11-05 10:49:42.136: NextBunch chunkID = 7943
2011-11-05 10:49:42.152: NextBunch chunkID = 7943
2011-11-05 10:49:42.152: NextBunch chunkID = 7943
2011-11-05 10:49:42.152: NextBunch chunkID = 7943
2011-11-05 10:49:42.152: NextBunch chunkID = 7943
2011-11-05 10:49:42.152: IOProcessor callback elapsed time: 110
2011-11-05 10:49:42.167: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:42.167: NextBunch chunkID = 7943
2011-11-05 10:49:42.183: NextBunch chunkID = 7943
2011-11-05 10:49:42.183: NextBunch chunkID = 7943
2011-11-05 10:49:42.199: NextBunch chunkID = 7943
2011-11-05 10:49:42.199: NextBunch chunkID = 7943
2011-11-05 10:49:42.199: NextBunch chunkID = 7943
2011-11-05 10:49:42.214: NextBunch chunkID = 7943
2011-11-05 10:49:42.214: NextBunch chunkID = 7943
2011-11-05 10:49:42.214: NextBunch chunkID = 7943
2011-11-05 10:49:42.230: NextBunch chunkID = 7943
2011-11-05 10:49:42.230: NextBunch chunkID = 7943
2011-11-05 10:49:42.230: NextBunch chunkID = 7943
2011-11-05 10:49:42.246: NextBunch chunkID = 7943
2011-11-05 10:49:42.246: NextBunch chunkID = 7943
2011-11-05 10:49:42.261: NextBunch chunkID = 7943
2011-11-05 10:49:42.261: NextBunch chunkID = 7943
2011-11-05 10:49:42.261: NextBunch chunkID = 7943
2011-11-05 10:49:42.277: ShardMigrationWriter::OnWriteReadyness()
2011-11-05 10:49:42.277: NextBunch chunkID = 7943
2011-11-05 10:49:42.277: NextBunch chunkID = 7943
2011-11-05 10:49:42.308: NextBunch chunkID = 7943
2011-11-05 10:49:42.308: NextBunch chunkID = 7943
2011-11-05 10:49:42.308: NextBunch chunkID = 7943
2011-11-05 10:49:42.308: NextBunch chunkID = 7943
2011-11-05 10:49:42.308: NextBunch chunkID = 7943
2011-11-05 10:49:42.308: NextBunch chunkID = 7943
2011-11-05 10:49:42.324: Cursor next chunk current chunkID = 7943
2011-11-05 10:49:42.324: ShardQuorumProcessor::BlockShard()
2011-11-05 10:49:42.324: Finished sending shard 24310...
2011-11-05 10:49:42.324: ShardMigrationWriter::OnWriteReadyness()
Assertion failed: quorumProcessor != 0, file ..\src\Application\ShardServer\Shar
dMigrationWriter.cpp, line 225

ScalienDB.exe!_NMSG_WRITE(int rterrnum) Line 217	C
ScalienDB.exe!abort() Line 71	C
ScalienDB.exe!_wassert(const wchar_t * expr, const wchar_t * filename, unsigned int lineno) Line 153	C
ScalienDB.exe!ShardMigrationWriter::OnWriteReadyness() Line 225 + 0x36 bytes	C++
ScalienDB.exe!MFunc::Thunk(void * arg) Line 81	C++
ScalienDB.exe!Callable::Execute() Line 22 + 0x3b bytes	C++
ScalienDB.exe!Call(Callable & callable) Line 39	C++
ScalienDB.exe!ClusterTransport::OnWriteReadyness(ClusterConnection * conn) Line 319	C++
ScalienDB.exe!ClusterConnection::OnWriteReadyness() Line 307	C++
ScalienDB.exe!TCPConnection::OnWrite() Line 173	C++
ScalienDB.exe!MFunc::Thunk(void * arg) Line 81	C++
ScalienDB.exe!Callable::Execute() Line 22 + 0x3b bytes	C++
ScalienDB.exe!Call(Callable & callable) Line 39	C++
ScalienDB.exe!CallWarnTimeout(Callable & callable) Line 115	C++
ScalienDB.exe!ProcessTCPWrite(TCPWrite * tcpwrite) Line 930	C++
ScalienDB.exe!IOProcessor::Poll(int msec) Line 761	C++
ScalienDB.exe!EventLoop::RunOnce() Line 69	C++
ScalienDB.exe!EventLoop::Run() Line 75 + 0x5 bytes	C++
ScalienDB.exe!RunApplication() Line 86	C++
ScalienDB.exe!Service::Main(int argc, char * * argv, void (void)* serviceFunc) Line 369	C++
ScalienDB.exe!RunMain(int argc, char * * argv) Line 57	C++
ScalienDB.exe!main(int argc, char * * argv) Line 28 + 0x14 bytes	C++
ScalienDB.exe!__tmainCRTStartup() Line 278 + 0x19 bytes	C
ScalienDB.exe!mainCRTStartup() Line 189	C
kernel32.dll!00000000778d652d()
[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]
ntdll.dll!0000000077a0c521()