sql: duplicate key value on non-unique index #23984

maddyblue · 2018-03-17T06:20:52Z

version (master branch at d23c18a + a patch dealing with the job registry): CockroachDB CCL v2.0-alpha.20180212-1682-g3d9738f

Running a job that does a bunch of updates (update players set skill = $1 where game = $2 and blizzid = $3) and got an error:

ERROR: duplicate key value (build,map,mode,hero_level)=(67,14,1,1) violates unique constraint "players_build_map_mode_hero_level_idx" (SQLSTATE 23505)

See the schema below. There is clearly no unique index beside the PK, and the UPDATE didn't change any columns in the PK.

For the schema:

CREATE TABLE players (
	game INT NOT NULL,
	mode INT NULL,
	"time" TIMESTAMP NULL,
	map INT NULL,
	length INT NULL,
	build INT NULL,
	region INT NULL,
	hero INT NULL,
	hero_level INT NULL,
	team INT NULL,
	winner BOOL NULL,
	blizzid INT NOT NULL,
	skill FLOAT NULL,
	battletag STRING COLLATE en_u_ks_level1 NULL,
	talents INT[] NULL,
	data JSON NULL,
	CONSTRAINT "primary" PRIMARY KEY (game ASC, blizzid ASC),
	INDEX players_region_blizzid_time_idx (region ASC, blizzid ASC, "time" DESC),
	INDEX players_region_battletag_idx (region ASC, battletag ASC),
	INDEX players_build_map_mode_hero_level_idx (build ASC, map ASC, mode ASC, hero_level ASC) STORING (hero, winner, skill),
	INDEX players_build_map_hero_level_idx (build ASC, map ASC, hero_level ASC) STORING (hero, winner),
	INDEX players_build_mode_hero_level_idx (build ASC, mode ASC, hero_level ASC) STORING (hero, winner, skill),
	INDEX players_build_hero_level_idx (build ASC, hero_level ASC) STORING (hero, winner),
	INDEX players_build_hero_idx (build ASC, hero ASC) STORING (winner, hero_level, length, map, mode),
	INDEX players_build_hero_map_mode_hero_level_idx (build ASC, hero ASC, map ASC, mode ASC, hero_level ASC) STORING (winner, talents, skill),
	INDEX players_build_hero_map_hero_level_idx (build ASC, hero ASC, map ASC, hero_level ASC) STORING (winner, talents),
	INDEX players_build_hero_mode_hero_level_idx (build ASC, hero ASC, mode ASC, hero_level ASC) STORING (winner, talents, skill),
	INDEX players_build_hero_hero_level_idx (build ASC, hero ASC, hero_level ASC) STORING (winner, talents),
	FAMILY "primary" (game, mode, "time", map, length, build, region, hero, hero_level, team, winner, blizzid, skill, battletag, talents, data)
)

The text was updated successfully, but these errors were encountered:

knz · 2018-03-17T08:39:33Z

So the most surprising thing from the UX perspective in this error is that not only does the UPDATE not change anything in the PK, it doesn't change anything in the conflicting index either.

however I think the logic in rowwriter's UpdateRow re-encodes every index when any value in the row is changed. I think this FK violation error can be encountered if the txn gets a conflict in-between the update to a PK and the update to a secondary index -- when another txn successfully writes to the same entry in the index "underneath". UpdateRow doesn't "see" that the txn is aborted and instead runs into a KV conflict and thinks it's a uniqueness violation.

This is precisely the scenario that @bdarnell and @nvanbenschoten were discussing yesterday.

@vivekmenezes I'm off for a week, this should be looked at by someone until then. Can you please divert until I'm back?

@jordanlewis can you check whether this is related to the FK issues that were seen during tpcc testing. I think it is. /cc @tschottdorf

knz · 2018-03-17T08:42:27Z

@mjibson the working hypothesis for that problem is that if your client retries the txn upon encountering this error, the error will disappear. I'm not sure in which scenario you found this, but perhaps a txn retry would be a workaround until the underlying problem is fixed? (Assuming the hypothesis is correct -- we're not yet 100% sure on that)

maddyblue · 2018-03-17T19:28:12Z

I reran the job an hour later and had the exact same error, so it doesn't appear to be a txn-related problem.

maddyblue · 2018-03-17T20:10:31Z

The code running this is at https://github.com/mjibson/hots.dog/blob/36a7b7834677505b6d342a19195c1de873e26757/elo.go#L203

It sets up a pgx pool and runs a bunch of updates from data incoming over a channel, so there's certainly lots of statements going through the same session, assuming the pool isn't making a new session each execution.

vivekmenezes · 2018-03-18T11:35:41Z

this involves an update to the STORING index where the value of the index is being modified.

INDEX players_build_map_mode_hero_level_idx (build ASC, map ASC, mode ASC, hero_level ASC) STORING (hero, winner, skill),

note an update to skill results in an update to this index.

maddyblue · 2018-03-18T15:34:56Z

Running these manually, this has nothing to do with retries. With no other transactions going on if I just run one of these by hand it fails with this same error. I'm not sure what I can do to get around it. It's delaying a feature :(. Is there any suspicion that using the 2.0 branch would improve this? I'm already on cluster version 2.0-1, so it's not trivial to just drop in a 2.0 binary otherwise I'd try.

bdarnell · 2018-03-18T16:55:36Z

So do you get different results for these two queries?

select * from players@primary where (build, map, mode, hero_level) = (67, 14, 1, 1);
select * from players@players_build_map_mode_hero_level_idx where (build, map, mode, hero_level) = (67, 14, 1, 1);

maddyblue · 2018-03-18T18:24:39Z

Ok update: I did a BACKUP, started up a release-2.0 cluster, RESTORE, and now everything seems fine.

Would it be useful to spin up a master cluster again to test those queries? Can do.

maddyblue · 2018-03-18T22:03:04Z

I was able to (accidentally) recreate this situation on a release-2.0 cluster. The above query returned identical results (13 rows each, no diff). I find it medium weird that a backup/restore cycle did something to change this. I was able to replicate that again just now (i.e, do a backup/restore and it works fine). So...this maybe got weirder.

maddyblue · 2018-03-20T05:46:41Z

I did a test to verify some things.

Started up a 1-node cluster with no existing data.
Ran the import data commands that produced the error from before.
Ran the update job that caused the error from before. The error occurred as expected.
Ran cockroach debug keys.
BACKUP/RESTORE into a new empty cluster (so the table IDs would be the same).
Ran cockroach debug keys on the new cluster.
Ran the update job which succeeded (as expected, and as before).
diff'd the old and new debug keys output. Surprisingly (maybe?), there were zero diffs in the table space above ID 50, which means this bug doesn't appear to be caused by data on disk in the table's data range. Diff is attached if anyone thinks it's interesting.

diff-keys.txt

I'll continue investigating tomorrow, but this appears to rule out things like intents or other on-disk transaction stuff.

maddyblue · 2018-03-21T03:13:12Z

More updates: doing a cockroach dump and then piping that in also makes the problem go away.

maddyblue · 2018-03-21T05:57:19Z

Tonight's analysis: added some debug prints during cputs and failures. When I drop all indexes except one, the error is the same. The CPut expected value is /BYTES/8103143a240000000000000000 (and it's the only CPut now since there's just the one index). The ConditionFailedError.ActualValue error value says it is: /BYTES/8103143a240000000000000000, which is exactly what the expected value was, so it is odd that the error is occurring.

bdarnell · 2018-03-21T15:19:17Z

Values contain a checksum, which is not included in their pretty-printed representation. Try printing that out too.

We tried phasing out the checksum here, but reverted it (#22637) because ConditionalPut considers checksums in deciding whether things match (#22636). CC @nvanbenschoten

nvanbenschoten · 2018-03-21T15:37:43Z

Interesting. If my memory serves me correctly, @mjibson did upgrade to the version with the checksum change before we pulled it. If the lack of a checksum on certain keys is causing this issue then it would make sense that dumping and restoring the data would fix it.

nvanbenschoten · 2018-03-21T17:42:14Z

I just talked to @mjibson and I was confused before. He's able to reproduce this on master with a fresh store, which means that this wasn't caused by the reverted change referenced above. That said, it does sound similar.

He's going to increase the logging of the ConditionFailedError to print out the full Value structs instead of the pretty-printed version of it. That will allow us to see if the checksums line up or if anything else is a problem.

Fixes cockroachdb#23984. Fixes cockroachdb#22636. In cockroachdb#22636 we noticed that conditional puts were not respecting the fact that Value checksums are meant to be optional. This is because they include checksums when performing the equality check between expected and existing values. This caused serious issues and forced us to roll back 75cbeb8. This was unfortunate, but the damage was contained. It demonstrated that we need to be very careful about changing checksums on values. Later, we found in cockroachdb#23984 that a path somewhere in IMPORT was forgetting to set checksums on Values. This was causing SQL operations at a much later time to fail for the same reason that 75cbeb8 caused issues. This bug will be fixed in a different change, but the fact that it exists shows how fragile the current approach is because despite the intention, checksums are absolutely not optional. This change addresses both of these problems by making checksums optional, as they were intended to be. CPut and InitPut no longer compare the checksums of the expected and existing values. Instead, they call into a new `EqualData` method, which ignores the checksum header when comparing byte values. This is a bit higher risk than most of the changes we've been accepting at this stage of the release cycle, but it would be really nice to get this change in to 2.0 so that we can stay on track with the timeline proposed in cockroachdb#22636 (comment) (although I'm not positive that the last step of the timeline is correct because I don't think we can rely on the "baked in" protection with such a low-level change). It will also save anyone who has used IMPORT already and hit cockroachdb#22636. This change should be safe from beneath Raft inconsistency for the same reason that 75cbeb8 was safe. All CPuts beneath Raft are still careful to set checksums, so we should not see any divergence in Raft state because of this error handling change. After this change, the only uses of `bytes.Equal(v1.RawBytes, v2.RawBytes)` are in tests and the `value.Equal` method. There may be an argument for making even `value.Equal` ignore the checksum header, although it isn't used outside of other `proto.Equal` methods. ``` Nathans-MacBook-Pro:cockroach$ grep -lRE 'bytes\.Equal$.*\.RawBytes,*,.*\.RawBytes,*$' pkg pkg/roachpb/data.pb.go pkg/storage/engine/mvcc_test.go ``` Release note: None

maddyblue assigned knz Mar 17, 2018

knz assigned vivekmenezes Mar 17, 2018

knz added C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. high priority labels Mar 17, 2018

nvanbenschoten mentioned this issue Mar 21, 2018

roachpb: enforce checksum optionality, add Value.EqualData method #24126

Merged

This was referenced Mar 21, 2018

importccl: set roachpb.Value checksums when creating data #24128

Merged

roachpb: value type is not BYTES #23946

Closed

nvanbenschoten closed this as completed in #24126 Mar 21, 2018

nvanbenschoten mentioned this issue Mar 21, 2018

backport-2.0: roachpb: enforce checksum optionality, add Value.EqualData method #24135

Merged

maddyblue mentioned this issue Mar 26, 2018

cherrypick-2.0: importccl: set roachpb.Value checksums when creating data #24221

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

sql: duplicate key value on non-unique index #23984

sql: duplicate key value on non-unique index #23984

maddyblue commented Mar 17, 2018

knz commented Mar 17, 2018 •

edited

Loading

knz commented Mar 17, 2018

maddyblue commented Mar 17, 2018

maddyblue commented Mar 17, 2018

vivekmenezes commented Mar 18, 2018

maddyblue commented Mar 18, 2018

bdarnell commented Mar 18, 2018

maddyblue commented Mar 18, 2018

maddyblue commented Mar 18, 2018

maddyblue commented Mar 20, 2018

maddyblue commented Mar 21, 2018

maddyblue commented Mar 21, 2018

bdarnell commented Mar 21, 2018

nvanbenschoten commented Mar 21, 2018

nvanbenschoten commented Mar 21, 2018

sql: duplicate key value on non-unique index #23984

sql: duplicate key value on non-unique index #23984

Comments

maddyblue commented Mar 17, 2018

knz commented Mar 17, 2018 • edited Loading

knz commented Mar 17, 2018

maddyblue commented Mar 17, 2018

maddyblue commented Mar 17, 2018

vivekmenezes commented Mar 18, 2018

maddyblue commented Mar 18, 2018

bdarnell commented Mar 18, 2018

maddyblue commented Mar 18, 2018

maddyblue commented Mar 18, 2018

maddyblue commented Mar 20, 2018

maddyblue commented Mar 21, 2018

maddyblue commented Mar 21, 2018

bdarnell commented Mar 21, 2018

nvanbenschoten commented Mar 21, 2018

nvanbenschoten commented Mar 21, 2018

knz commented Mar 17, 2018 •

edited

Loading