I'm not too sure what's happening as I don't understand the interrelationship of all the the relevant classes.

I figured out where the test diverges from when it succeeds with a bunch of printfs.

Hacky printfs: https://chromium-review.googlesource.com/c/chromium/src/+/644247

Success followed by failure output: https://gist.githubusercontent.com/sgraham/0a5817d527c2c77f063011f8d9c44d4d/raw/b354071516171b202488e7880d64a98f6eec0687/gistfile1.txt

It seems to be related to in the OK case, ListOriginsAndLastModifiedOnTaskRunner() pushes an unknown size because the file_info and index timestamps are typically the same.

[00003.095] 06470.06497> [3:69570009:0830/202546.721313:3095006:ERROR:cache_storage_manager.cc(94)] comparing 2017-08-30 20:25:46.000 UTC vs. 2017-08-30 20:25:46.000 UTC
[00003.095] 06470.06497> [3:69570009:0830/202546.721389:3095081:ERROR:cache_storage_manager.cc(98)]   pushing=http://example1.com/, -1

But in the failing case, the timestamps differ by 1s, so it pushes the actual size of the data, which changes later execution.

[00003.378] 07076.07103> [3:160571927:0830/202547.005065:3378758:ERROR:cache_storage_manager.cc(94)] comparing 2017-08-30 20:25:46.000 UTC vs. 2017-08-30 20:25:47.000 UTC
[00003.378] 07076.07103> [3:160571927:0830/202547.005176:3378869:ERROR:cache_storage_manager.cc(98)]   pushing=http://example1.com/, 287
[00003.379] 07076.07103> [3:160571927:0830/202547.005323:3379016:ERROR:cache_storage_manager.cc(336)] continue because not unknown


But that's too deep in the weeds for me to clearly see why that breaks the test at the moment. (Maybe that's symptomatic of reading data from the older "deleted" data store?)

I haven't quite nailed down the specific problem, but I think it's related to ListOriginsAndLastModifiedOnTaskRunner() looking at the timestamp on the directory where the index is stored, and comparing it to the timestamp of the index file itself: https://cs.chromium.org/chromium/src/content/browser/cache_storage/cache_storage_manager.cc?rcl=51be2e3ca3d30e0e0cf96fa926464e5f1d095431&l=92

e.g. I think it's comparing last_modified of
  /tmp/.org.chromium.Chromium.JdhbDK/Service Worker/CacheStorage/0430f1a484a0ea6d8de562488c5fbeec0111d16f/
to last_modified of:
  /tmp/.org.chromium.Chromium.JdhbDK/Service Worker/CacheStorage/0430f1a484a0ea6d8de562488c5fbeec0111d16f/index.txt

Is that what was intended there? https://codereview.chromium.org/2416713002 Or does it need to check the data in the cache dirs or something instead? (I'm pretty lost, sorry if that makes no sense).

After further discussion and investigation, it looks like putting a file into a dir doesn't necessarily update the timestamp (right away?)

In https://gist.githubusercontent.com/sgraham/3a8c492e0d5f1c1dbd3d8faaf1ec6089/raw/051a7bf036e8dd20b902f530a531bf310ec216bb/gistfile1.txt


0430f1a484a0ea6d8de562488c5fbeec0111d16f/a1bbbb4f-56e0-42b1-8bbe-049089460589/60addad22da8da2d_0

and

0430f1a484a0ea6d8de562488c5fbeec0111d16f/a1bbbb4f-56e0-42b1-8bbe-049089460589/32eee27b08e1ed0b_0

have mtimes of 23:12:00.000 and 23:12:01.000 respectively, but the parent directory 0430f1a484a0ea6d8de562488c5fbeec0111d16f/a1bbbb4f-56e0-42b1-8bbe-049089460589 has an mtime of 23:12:00.000.

So unless the subfile #2 is created and then modified (?) it seems that the parent directory ought to have updated.

Re #4: IIUC the code at https://cs.chromium.org/chromium/src/content/browser/cache_storage/cache_storage_manager.cc?rcl=51be2e3ca3d30e0e0cf96fa926464e5f1d095431&l=92 is comparing the mtime of the index file against that of the containing directory, presumably with the expectation that if any file is added or removed from the directory (thereby affecting the cache size) then its mtime will exceed that of the index.

However, for that to make sense you'd have to create new files somewhere else, and then move them into place, so that they are already of the final size before the directory mtime is updated, otherwise there is a race between the file being added, us updating the cache size, and the file actually being filled with data.

Filed what I think might be the cause upstream at MG-1086. The summary is that creating a file inside a directory on Fuchsia (at least in /tmp) updates the timestamp of the directory, but it can still be < the timestamp of the newly created file.

POSIX seems slightly unclear on this, but that seems like odd behaviour anyway.

This in turn means that this test fails because the retrieval of used size in ListOriginsAndLastModifiedOnTaskRunner() doesn't see the Put of the second key so that retrieved size is returning stale data.

Following up for completeness (and because I have the memory of a goldfish), the parent dir timestamp doesn't appear to be updated at all after open(). So that's a lot simpler, and makes it more clearly a Fuchsia-side thing.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/ffd9654d27e456ddf734c3421a29e2a7e57fa8a0

commit ffd9654d27e456ddf734c3421a29e2a7e57fa8a0
Author: Scott Graham <scottmg@chromium.org>
Date: Thu Aug 31 17:32:23 2017

Roll Fuchsia SDK to 2947889cf6f6a53dcd9826e4ce41316920fcb05c

Includes fix for parent dir mtime not being updated (MG-1086).

Bug: 707030, 760687
Change-Id: I2e0fe0febf060f12b25ed8fbff5a3f64afd926d7
TBR: wez@chromium.org
Reviewed-on: https://chromium-review.googlesource.com/646371
Reviewed-by: Scott Graham <scottmg@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Reviewed-by: Sergey Ulanov <sergeyu@chromium.org>
Commit-Queue: Scott Graham <scottmg@chromium.org>
Commit-Queue: Wez <wez@chromium.org>
Cr-Commit-Position: refs/heads/master@{#498908}
[modify] https://crrev.com/ffd9654d27e456ddf734c3421a29e2a7e57fa8a0/DEPS

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/f7bb7ea4f91fcc4cd9c140f8b2c092db704e268c

commit f7bb7ea4f91fcc4cd9c140f8b2c092db704e268c
Author: Scott Graham <scottmg@chromium.org>
Date: Thu Aug 31 17:32:46 2017

fuchsia: Update content_unittests filter for recent changes/flakes

- AudioRendererSinkCacheTest.SmokeTest was fixed by making gtest
  threadsafe (rolled already)
- BrowsingDataRemoverImplTest.MultipleTasks is yet-another sqlite one
  that needs locks (just moved in the filter)
- CacheStorageManagerTest.GetAllOriginsUsageWithOldIndex was fixed in
  Fuchsia and by SDK roll elsewhere (mtime fix for parent dirs)
- RendererAudioOutputStreamFactoryIntegrationTest.StreamIntegrationTest
  was (likely) also fixed by the gtest fix. (At least, it uses gmock,
  and I can't reproduce failure any more.
- URLLoaderImplTest.CantSniffEmptyHtml has flaked a few times, disable
  it along with the rest of the URLLoaderImplTest
- NavigationURLLoaderTest.RequestFailedCertError and
  NavigationURLLoaderTest.RequestFailedCertErrorFatal started failing
  after the SDK roll, disable.

Bug: 760687,  759916 ,  754861 ,  761033 
Change-Id: I53baaa13f7526172675f44cba1aee9371b6dfac2
TBR: wez@chromium.org
Reviewed-on: https://chromium-review.googlesource.com/646527
Commit-Queue: Scott Graham <scottmg@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Reviewed-by: Scott Graham <scottmg@chromium.org>
Cr-Commit-Position: refs/heads/master@{#498909}
[modify] https://crrev.com/f7bb7ea4f91fcc4cd9c140f8b2c092db704e268c/testing/buildbot/filters/fuchsia.content_unittests.filter

This test had a slightly different problem

[00039.375] 02844.02957> [ RUN      ] CacheStorageManagerTest.GetAllOriginsUsageWithOldIndex
[00039.376] 02844.02957> ../../content/browser/cache_storage/cache_storage_manager_unittest.cc:1077: Failure
[00039.377] 02844.02957> Value of: IsIndexFileCurrent(storage_dir)
[00039.377] 02844.02957>   Actual: false
[00039.377] 02844.02957> Expected: true
[00039.378] 02844.02957> [  FAILED  ] CacheStorageManagerTest.GetAllOriginsUsageWithOldIndex (1575 ms)
[00039.378] 02844.02957> [510/4554] CacheStorageManagerTest.GetAllOriginsUsageWithOldIndex (1575 ms)

https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Fchromium.fyi%2FFuchsia%2F9296%2F%2B%2Frecipes%2Fsteps%2Fcontent_unittests%2F0%2Fstdout

The mtimes should be fixed so this is likely a different-but-possibly-related problem.

https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Fchromium.fyi%2FFuchsia%2F9320%2F%2B%2Frecipes%2Fsteps%2Fcontent_unittests%2F0%2Fstdout too 

Is the GetAllOriginsUsageWithOldIndex test flaky, or is this a consistent error?

Also, just trying to verify -- if "IsIndexFileCurrent" actually failing because of a mismatching mtime, or due to a readdir/stat issue?

Sorry, I didn't mean to have you try to debug it, just fyi.

It's failing flakily.

I haven't had a chance to dig in to determine the precise cause yet, so could be completely unrelated to the mtime fix.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/6fa1c0867a946630d7afff8edd6a30d21f5a4676

commit 6fa1c0867a946630d7afff8edd6a30d21f5a4676
Author: Scott Graham <scottmg@chromium.org>
Date: Fri Sep 15 21:06:15 2017

fuchsia: Disable a couple of tests that flake sometimes

TBR: sergeyu@chromium.org
Bug: 759653, 760687
Change-Id: I36ad501e836a96df38bd65052b8c42bf8f38321b
Reviewed-on: https://chromium-review.googlesource.com/669364
Commit-Queue: Scott Graham <scottmg@chromium.org>
Reviewed-by: Scott Graham <scottmg@chromium.org>
Cr-Commit-Position: refs/heads/master@{#502369}
[modify] https://crrev.com/6fa1c0867a946630d7afff8edd6a30d21f5a4676/testing/buildbot/filters/fuchsia.content_unittests.filter

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/45cfea793a845c6b8cdfbd515391293189af3be9

commit 45cfea793a845c6b8cdfbd515391293189af3be9
Author: Scott Graham <scottmg@chromium.org>
Date: Mon Sep 18 18:57:29 2017

fuchsia: Disable a few content_unittests that flaked recently

TBR: sergeyu@chromium.org
Bug: 760687, 766221 ,766223
Change-Id: Ice03f167b78c8ce6ca1efebc54c78d3c3c187663
Reviewed-on: https://chromium-review.googlesource.com/671494
Reviewed-by: Scott Graham <scottmg@chromium.org>
Reviewed-by: Sergey Ulanov <sergeyu@chromium.org>
Commit-Queue: Scott Graham <scottmg@chromium.org>
Cr-Commit-Position: refs/heads/master@{#502627}
[modify] https://crrev.com/45cfea793a845c6b8cdfbd515391293189af3be9/testing/buildbot/filters/fuchsia.content_unittests.filter