Use of CookieMonster::SetCanonicalCookieAsync can result in duplicate creation times, borking persistent DB |
|||||||||||||||||
Issue description"benchmarks.system_health_smoke_test.SystemHealthBenchmarkSmokeTest.system_health.memory_desktop.multitab:misc:typical24" is flaky. This issue was created automatically by the chromium-try-flakes app. Please find the right owner to fix the respective test/step and assign this issue to them. If the step/test is infrastructure-related, please add Infra-Troopers label and change issue status to Untriaged. When done, please remove the issue from Sheriff Bug Queue by removing the Sheriff-Chromium label. We have detected 3 recent flakes. List of all flakes can be found at https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyggELEgVGbGFrZSJ3YmVuY2htYXJrcy5zeXN0ZW1faGVhbHRoX3Ntb2tlX3Rlc3QuU3lzdGVtSGVhbHRoQmVuY2htYXJrU21va2VUZXN0LnN5c3RlbV9oZWFsdGgubWVtb3J5X2Rlc2t0b3AubXVsdGl0YWI6bWlzYzp0eXBpY2FsMjQM. Flaky tests should be disabled within 30 minutes unless culprit CL is found and reverted. Please see more details here: https://sites.google.com/a/chromium.org/dev/developers/tree-sheriffs/sheriffing-bug-queues#triaging-auto-filed-flakiness-bugs This flaky test/step was previously tracked in issue 698499 .
,
Jan 12 2018
Detected 4 new flakes for test/step "benchmarks.system_health_smoke_test.SystemHealthBenchmarkSmokeTest.system_health.memory_desktop.multitab:misc:typical24". To see the actual flakes, please visit https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyggELEgVGbGFrZSJ3YmVuY2htYXJrcy5zeXN0ZW1faGVhbHRoX3Ntb2tlX3Rlc3QuU3lzdGVtSGVhbHRoQmVuY2htYXJrU21va2VUZXN0LnN5c3RlbV9oZWFsdGgubWVtb3J5X2Rlc2t0b3AubXVsdGl0YWI6bWlzYzp0eXBpY2FsMjQM. This message was posted automatically by the chromium-try-flakes app.
,
Jan 15 2018
Removing the label since an owner looks assigned.
,
Jan 17 2018
Ok, pretty sure I know what's going on here. I believe this was regressed in https://chromium-review.googlesource.com/c/chromium/src/+/775606, which, at the site where cookies returned from servers are being set in the local cookie store, replaced SetCookieWithOptionsAsync() with SetCanonicalCookieAsync(). CanonicalCookie::Create() requires a creation time, whereas a null creation time to SetCookieWithOptionsAsync() indicates "pick one". The reason the latter is preferred is that (sadly, but it'd be pretty hard to change) the on-disk cookie DB requires creation times to be unique, and "pick one" makes sure to pick a unique value. So switching to SetCanonicalCookieAsync() violates the uniqueness constraint, but only on machines with coarse timers (which is why this flake is windows specific) and only sometimes (which is why it's a flake :-}). I'll work on a fix.
,
Jan 17 2018
Victor: You should be aware of this, because in an ideal world the restricted cookie manager interface shouldn't allow setting the creation time, and in the pretty close to ideal world in which we live, the RCM implementation should assert that creation times specified by incoming cookies are null. This does cause a problem with cookie lines that specify expiration by age (because we don't have a way to encode age in a CanonicalCookie, only expiration). I'm not sure how to manage this; we could tweak the RestrictedCookieManager interface away from CanonicalCookie, though that seems sad. Though actually, now that I think of it, there's absolutely no problem parsing a max-age specified for a cookie against the current time and setting the CC that way--it's just the creation time should be null so that it's set (uniquely) when the CC hits the network service.
,
Jan 19 2018
Thank you very much, Randy! I will try to put together a CL soon.
,
Jan 19 2018
I'm already halfway into a CL (https://chromium-review.googlesource.com/c/chromium/src/+/872175); you might want to just leave it to me.
,
Jan 23 2018
Sorry for being unclear earlier! My earlier commeant meant I'd put together a CL for RestrictedCookieManager, which would essentially be a check / assignment plus unit tests. The following review comment for the CL you referenced makes me think that's still desirable. https://chromium-review.googlesource.com/c/chromium/src/+/872175/2/net/cookies/canonical_cookie.cc#94 Did I understand correctly?
,
Jan 23 2018
Ah! Sorry I misunderstood. I'd say hold off on that, at least until I do the design writeup mentioned in https://chromium-review.googlesource.com/c/chromium/src/+/872175; we may end up deciding we need to solve this at a different level. I expect I'll have that writeup within the next day or two.
,
Jan 26 2018
See https://docs.google.com/document/d/1xbQHdDsDZTss-iBf3QparZLtCavFa6l83Cl802KjX5k/edit for the design summary referred to above. Open to all chromium accounts, happy to grant comment access to others upon request.
,
Jan 27 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/e6515d6ae158f5b53b8ee697cdd99d714a8ab402 commit e6515d6ae158f5b53b8ee697cdd99d714a8ab402 Author: Randy Smith <rdsmith@chromium.org> Date: Sat Jan 27 03:57:32 2018 Revert section of https://chromium-review.googlesource.com/c/chromium/src/+/775606 that is causing collisions on cookie creation time. This is a quick fix of problems being seen in the field; a longer term fix is being tracked in http://crbug.com/800414 . Bug: 800414 Bug: 795827 Bug: 794453 Change-Id: I0ff206fdc517e20f270cebadc6b64704f4c18d21 Reviewed-on: https://chromium-review.googlesource.com/889958 Reviewed-by: Matt Menke <mmenke@chromium.org> Commit-Queue: Randy Smith <rdsmith@chromium.org> Cr-Commit-Position: refs/heads/master@{#532152} [modify] https://crrev.com/e6515d6ae158f5b53b8ee697cdd99d714a8ab402/net/url_request/url_request_http_job.cc
,
Jan 29 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/69ec2285028f3261757b8e3edc6f64316c085186 commit 69ec2285028f3261757b8e3edc6f64316c085186 Author: Randy Smith <rdsmith@chromium.org> Date: Mon Jan 29 20:35:23 2018 Revert section of https://chromium-review.googlesource.com/c/chromium/src/+/775606 that is causing collisions on cookie creation time. This is a quick fix of problems being seen in the field; a longer term fix is being tracked in http://crbug.com/800414 . Bug: 800414 Bug: 795827 Bug: 794453 Change-Id: I0ff206fdc517e20f270cebadc6b64704f4c18d21 Reviewed-on: https://chromium-review.googlesource.com/889958 Reviewed-by: Matt Menke <mmenke@chromium.org> Commit-Queue: Randy Smith <rdsmith@chromium.org> Cr-Original-Commit-Position: refs/heads/master@{#532152}(cherry picked from commit e6515d6ae158f5b53b8ee697cdd99d714a8ab402) Reviewed-on: https://chromium-review.googlesource.com/891642 Reviewed-by: Victor Costan <pwnall@chromium.org> Cr-Commit-Position: refs/branch-heads/3325@{#153} Cr-Branched-From: bc084a8b5afa3744a74927344e304c02ae54189f-refs/heads/master@{#530369} [modify] https://crrev.com/69ec2285028f3261757b8e3edc6f64316c085186/net/url_request/url_request_http_job.cc
,
Jan 29 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/d4965708362a62489b05e8d447b59cc101789369 commit d4965708362a62489b05e8d447b59cc101789369 Author: Randy Smith <rdsmith@chromium.org> Date: Mon Jan 29 23:46:43 2018 Revert section of https://chromium-review.googlesource.com/c/chromium/src/+/775606 that is causing collisions on cookie creation time. This is a quick fix of problems being seen in the field; a longer term fix is being tracked in http://crbug.com/800414 . Bug: 800414 Bug: 795827 Bug: 794453 Change-Id: I0ff206fdc517e20f270cebadc6b64704f4c18d21 Reviewed-on: https://chromium-review.googlesource.com/889958 Reviewed-by: Matt Menke <mmenke@chromium.org> Commit-Queue: Randy Smith <rdsmith@chromium.org> Cr-Original-Commit-Position: refs/heads/master@{#532152}(cherry picked from commit e6515d6ae158f5b53b8ee697cdd99d714a8ab402) Reviewed-on: https://chromium-review.googlesource.com/891564 Reviewed-by: Victor Costan <pwnall@chromium.org> Cr-Commit-Position: refs/branch-heads/3282@{#610} Cr-Branched-From: 5fdc0fab22ce7efd32532ee989b223fa12f8171e-refs/heads/master@{#520840} [modify] https://crrev.com/d4965708362a62489b05e8d447b59cc101789369/net/url_request/url_request_http_job.cc
,
Feb 1 2018
Issue 806870 has been merged into this issue.
,
Feb 1 2018
Quick update: This is now the primary tracking bug for the problem triggered by https://chromium-review.googlesource.com/c/chromium/src/+/775606 and hopefully quick-fixed by my recent change. This bug will also track the long term fixing of the root cause for this issue; see the design doc mentioned in c#10. Issue 795827 is tracking the instance of login problems that were present before the above CL was landed.
,
Feb 2 2018
,
Feb 7 2018
Folks: I have an initial draft of the post-mortem for this problem in https://docs.google.com/document/d/1zU29zLK4hJp07gqbR4lrztehBZoMvHB5iDRJLiaaZmU/edit if anyone's interested.
,
Feb 16 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/23f4922cd6206fab60dd7fee798ed325ab982171 commit 23f4922cd6206fab60dd7fee798ed325ab982171 Author: Randy Smith <rdsmith@chromium.org> Date: Fri Feb 16 02:56:14 2018 Shift on-disk Cookie DB scheme uniquification constraints. Historically, the on-disk Cookie DB has required unique creation time across all cookies, which is not a restriction classes higher in the stack have or enforce. This CL shifts the unique constraint over to (name, domain, path), which is supported by the spec. Bug: 800414 Change-Id: I8ab14f2a2cf81257ef51a34aca78a80f1886e356 Reviewed-on: https://chromium-review.googlesource.com/906675 Commit-Queue: Randy Smith <rdsmith@chromium.org> Reviewed-by: Ilya Sherman <isherman@chromium.org> Reviewed-by: Victor Costan <pwnall@chromium.org> Reviewed-by: Helen Li <xunjieli@chromium.org> Cr-Commit-Position: refs/heads/master@{#537154} [modify] https://crrev.com/23f4922cd6206fab60dd7fee798ed325ab982171/net/extras/sqlite/sqlite_persistent_cookie_store.cc [modify] https://crrev.com/23f4922cd6206fab60dd7fee798ed325ab982171/net/extras/sqlite/sqlite_persistent_cookie_store_perftest.cc [modify] https://crrev.com/23f4922cd6206fab60dd7fee798ed325ab982171/net/extras/sqlite/sqlite_persistent_cookie_store_unittest.cc [modify] https://crrev.com/23f4922cd6206fab60dd7fee798ed325ab982171/tools/metrics/histograms/histograms.xml
,
Feb 16 2018
After the fix in c#18 has made it all the way out to stable without blowing up, the reversion in c#11 should be reverted (it's no longer relevant). I won't be around to actually do that, so I'm shifting the ownership of this bug over to pwnall@, who was the author of the original change that was (very partially in a targeted fashion) reverted in c#11. Also +mmenke, as I think he'll hear about it if something blows up from c#18 before pwnall@ will.
,
Feb 16 2018
Note that issue 813141 should probably be resolved before doing the un-revert described in c#19; see that issue for more details.
,
Feb 16 2018
,
Feb 16 2018
I'll also suggest that after the schema change flushes through the channels the use of CurrentTime() in cookie_monster.cc be removed.
,
Mar 2 2018
,
Apr 4 2018
Issue 811057 has been merged into this issue.
,
Apr 9 2018
,
Apr 10 2018
I get the feeling that a lot of people are going to lose their cookies after upgrading to Chrome 66.
The following query returns 997 cookies (out of 6145) on one of my machines and 366 on another (out of 2464):
SELECT COUNT(*) FROM (
SELECT host_key, name, path, COUNT(*)
FROM cookies
GROUP BY host_key, name, path
HAVING COUNT(*) > 1);
So about 15% of my cookies are duplicate, whereas the comments in sqlite_persistent_cookie_store.cc indicate this should be very uncommon:
// If any cookies violate the new uniqueness constraints (no two
// cookies with the same (name, domain, path)) erase the cookie store.
// That "shouldn't happen", which means probably not too many users'
// cookie stores will have it.
I'm all for starting over, but I do hope that it's understood that a lot of cookies will probably get tossed.
,
Apr 10 2018
Uff. That's a good point, and it may be worth doing some better sort of recovery of it (e.g. similar to "pick most recent" thing CookieMonster does), but we might be too close to M66 to address that w/o too much of a risk.
,
Apr 10 2018
Sounds like yet another good reason to turn off updates. There is at time a lot of change for it's own sake.
,
Apr 10 2018
If we have multiple matching cookies, do we send them both, or just a random one? I'm not an expert here, but I would have assumed we only send one cookie per name per request.
,
Apr 10 2018
Same name, different but relevant domains (or host)? Looks like all of them, and I won't know off the top of my head whether that's correct. What's the connection with the previous discussion, anyway? (This very site seems to have a _ga cookie sent for bugs.chromium.org and chromium.org both, with slightly different values) https://cs.chromium.org/chromium/src/net/cookies/canonical_cookie.cc?sq=package:chromium&dr&l=475 Looks like we at least want to send multiple ones with an empty name. https://cs.chromium.org/chromium/src/net/url_request/url_request_http_job.cc?q=url_request_http_job.cc&sq=package:chromium&dr&l=689
,
Apr 11 2018
re: comment #26: so there is a not-very-good way of checking for it in our histograms, at around when this was first rolled out: looking at the size of the [0, 1) bucket in Cookie.NumberOfLoadedCookies as the new version rolls out to various channels, cross-referencing to SQLite.Version.Cookie and Cookie.TimeDatabaseMigrationToV10. I am not really seeing any jump in opening the empty store even during days when a lot of users convert over. This way too crude a method to exclude a substantial portion of population being affected, but it at least looks to not be of apocalyptic proportions.
,
Apr 11 2018
The connection with the previous discussion is that if we were only sending one cookie, anyways, removing cookies with the same name/path/domain would not be harmful, as long as we either removed the ones we didn't generally send, or sent a random one.
,
Apr 11 2018
Well, what comment #26 is about is that the V9 -> V10 schema migration code erases *all* the cookies if the uniqueness constraint on (name, path, domain) is violated. We do actually also drop duplicates with same (name, path, domain) inside CookieMonster --- that's the algorithm you suggested improvements to last time you were reviewing my CL. Things with same name but different path and domain will all be sent, however, when relevant, but they're also not going to hit the uniqueness constraint on the 3-tuple.
,
Apr 11 2018
I can't be that unique of a snowflake to have so many duplicate cookies (unless it somehow only happens with my Arch Linux Chromium build). I checked again on my laptop and count 4 more duplicate cookies since my previous comment.
This is the most recent one:
sqlite> SELECT host_key, name, path, datetime(
(creation_utc - 11644473600000000) / 1000000, 'unixepoch')
FROM cookies WHERE name = 'SESSIONDATA' ORDER BY creation_utc;
.imgur.com|SESSIONDATA|/|2017-11-18 03:53:18
.imgur.com|SESSIONDATA|/|2018-04-11 14:32:54
(FWIW the first cookie expires on 2018-05-17 and the new one on 2018-10-08; last_access_utc is the same as creation_utc.)
Can't argue with metrics though, and if someone can run the query from comment #26 on a cookie database from an old and heavily used (preferably on Linux) Chrome 65 installation, that would provide extra reassurance (or worry, if the query returns anything).
Finally, something that's been bugging me: Shouldn't kCompatibleVersionNumber have been bumped to 10 because of the two column renames (and thus the table can't be used by Chrome < 66)?
,
Apr 11 2018
re: you seeing duplicates: any chance there are some warnings mentioning os_crypt or oscrypt if you run Chrome with --enable-logging --v=1?
,
Apr 11 2018
If you meant at startup, no; only the expected "OSCrypt using Libsecret as backend." message.
,
Apr 12 2018
I experimented a bit on the SESSIONDATA cookie from imgur.com that I mentioned in comment #34. After removing the new cookie and visiting imgur.com, I get a duplicate cookie again. I think what's happening is that the old cookie is ignored and not loaded, which leads me to believe Chromium is having trouble decrypting its encrypted_value. On both affected machines, the cookie duplication started happening on 2017-11-18, which strongly suggests I was an idiot that day and removed "Chromium Safe Storage" from my keyring. I faintly remember doing some "cleanup" on my keyrings a few months ago... ** TL;DR ** Mystery solved, it was my fault for removing the encryption passphrase Chromium had stored in the keyring. This made Chromium unable to load the old cookies and it created duplicate ones. @morlovich: The metrics probably paint a good overall picture and the impact is very minimal. Thanks for looking into it, and I think we can be confident that only very few users doing silly things like me will lose cookies. (Sorry for the noise as well.)
,
Apr 13 2018
@pwnall: re [1] -- I see a possible issue: Since the compatible version is updated only during migrations, existing users of Chrome 66 Beta will have that set to 5 until a future migration to version 11. Furthermore, if the CL doesn't get backported to the M66 branch, only users upgrading from Chrome 65 straight to Chrome 67 will end up with the correct database version. (Please correct me if I'm wrong.) Maybe it's not too important though? Also, a final thought regarding my duplicate cookies situation: If a cookie's value cannot be decrypted on load, when the cookie is added again during a session and then flushed to the persistent sqlite store, it'll trigger a constraint failure on (host_key, name, path). [2] The cookie is somehow still saved to the Cookies db, even though Chromium prints an error about the insertion failure. (I haven't been able to figure out how it manages to overwrite the invalid cookie.) Perhaps it would make sense to change add_smt from "INSERT INTO" to "INSERT OR REPLACE INTO" to convey the intention to overwrite any old invalid/undecryptable cookies. [1] https://chromium-review.googlesource.com/c/chromium/src/+/1008413 [2] [..:ERROR:connection.cc(1888)] Cookie sqlite error 2067, errno 0: UNIQUE constraint failed: cookies.host_key, cookies.name, cookies.path, sql: INSERT INTO cookies (..)
,
Apr 23 2018
Detected 3 new flakes for test/step "benchmarks.system_health_smoke_test.SystemHealthBenchmarkSmokeTest.system_health.memory_desktop.multitab:misc:typical24". To see the actual flakes, please visit https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyggELEgVGbGFrZSJ3YmVuY2htYXJrcy5zeXN0ZW1faGVhbHRoX3Ntb2tlX3Rlc3QuU3lzdGVtSGVhbHRoQmVuY2htYXJrU21va2VUZXN0LnN5c3RlbV9oZWFsdGgubWVtb3J5X2Rlc2t0b3AubXVsdGl0YWI6bWlzYzp0eXBpY2FsMjQM. This message was posted automatically by the chromium-try-flakes app. Since flakiness is ongoing, the issue was moved back into Sheriff Bug Queue (unless already there).
,
Apr 23 2018
,
Apr 23 2018
Detected 4 new flakes for test/step "benchmarks.system_health_smoke_test.SystemHealthBenchmarkSmokeTest.system_health.memory_desktop.multitab:misc:typical24". To see the actual flakes, please visit https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyggELEgVGbGFrZSJ3YmVuY2htYXJrcy5zeXN0ZW1faGVhbHRoX3Ntb2tlX3Rlc3QuU3lzdGVtSGVhbHRoQmVuY2htYXJrU21va2VUZXN0LnN5c3RlbV9oZWFsdGgubWVtb3J5X2Rlc2t0b3AubXVsdGl0YWI6bWlzYzp0eXBpY2FsMjQM. This message was posted automatically by the chromium-try-flakes app. Since flakiness is ongoing, the issue was moved back into Sheriff Bug Queue (unless already there).
,
Apr 23 2018
Hmm, I am not sure there is any reason to believe these flakes are related to the original issue; I am certainly not seeing the same check failure. Is there any way of telling the bot to file a new issue, so it can be triaged separately?
,
Apr 23 2018
I told the bot to file a new bug.
,
Apr 25 2018
Bot filed bug 836447 , FYI.
,
May 21 2018
Bulk edit** This bug has the label Postmortem-Followup but has not been updated in 3+ weeks. We are working on a new workflow to improve postmortem followthrough. Postmortems and postmortem bugs are very important in making sure we don't repeat prior mistakes and for making Chrome better for all. We will be taking a closer look at these bugs in the coming weeks. Please take some time to work on this, reassign, or close if the issue has been fixed. Thank you.
,
May 21 2018
The cookie DB no longer has an uniqueness constraint on the creation time. We now require that the combination of (domain, path, cookie name) is unique instead. |
|||||||||||||||||
►
Sign in to add a comment |
|||||||||||||||||
Comment 1 by clamy@chromium.org
, Jan 10 2018Owner: rdsmith@chromium.org
Status: Assigned (was: Untriaged)