IndexedDB: Added timing histograms.

IndexedDB: Added timing histograms.

Specifically:
WebCore.IndexedDB.LevelDB.OpenTime.Disk
WebCore.IndexedDB.LevelDB.PutTime
WebCore.IndexedDB.LevelDB.WriteTime
WebCore.IndexedDB.LevelDB.Transaction.CommitTime

BUG=397552
Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=289895

[jsbell, 2014-08-13 22:49:11]

Is this final? Is the intent to land this and then some additional higher-level
(e.g. duration from open() call to success/error) metrics elsewhere?

Needs tools/metrics/histograms/histograms.xml additions

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
File content/browser/indexed_db/leveldb/leveldb_database.cc (right):

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
content/browser/indexed_db/leveldb/leveldb_database.cc:289:
UMA_HISTOGRAM_MEDIUM_TIMES("WebCore.IndexedDB.LevelDB.OpenTime.Disk",
Assumes anything < 10 seconds is "fast enough" and we don't need to break it
down further? Sounds okay.

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
content/browser/indexed_db/leveldb/leveldb_database.cc:343: leveldb::Status
LevelDBDatabase::Remove(const StringPiece& key) {
Why no histogram here?

[cmumford, 2014-08-13 23:53:03]

The last thing that I'd like to add is one more measurement in the render
process for the total IDB open time - i.e. to get as close to the JavaScript
implementation as possible.

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
File content/browser/indexed_db/leveldb/leveldb_database.cc (right):

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
content/browser/indexed_db/leveldb/leveldb_database.cc:289:
UMA_HISTOGRAM_MEDIUM_TIMES("WebCore.IndexedDB.LevelDB.OpenTime.Disk",
On 2014/08/13 22:49:11, jsbell wrote:
> Assumes anything < 10 seconds is "fast enough" and we don't need to break it
> down further? Sounds okay.

If I'm reading the code correctly then UMA_HISTOGRAM_MEDIUM_TIMES is 10msec < h
< 3min. I'm not sure if times < 10msec are ignored, or rounded up to to 10msec.

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
content/browser/indexed_db/leveldb/leveldb_database.cc:343: leveldb::Status
LevelDBDatabase::Remove(const StringPiece& key) {
On 2014/08/13 22:49:11, jsbell wrote:
> Why no histogram here?

No reason. Your bug only mentioned open & commit so I figured I'd post this and
you'd mention any other functions you'd like measured in this review.

I'll go ahead and measure Remove().

[dgrogan, 2014-08-13 23:55:18]

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
File content/browser/indexed_db/leveldb/leveldb_database.cc (right):

https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
content/browser/indexed_db/leveldb/leveldb_database.cc:289:
UMA_HISTOGRAM_MEDIUM_TIMES("WebCore.IndexedDB.LevelDB.OpenTime.Disk",
On 2014/08/13 23:53:02, cmumford wrote:
> On 2014/08/13 22:49:11, jsbell wrote:
> > Assumes anything < 10 seconds is "fast enough" and we don't need to break it
> > down further? Sounds okay.
> 
> If I'm reading the code correctly then UMA_HISTOGRAM_MEDIUM_TIMES is 10msec <
h
> < 3min. I'm not sure if times < 10msec are ignored, or rounded up to to
10msec.

They'll show up in the 0 bucket.

[jsbell, 2014-08-14 00:16:53]

On 2014/08/13 23:55:18, dgrogan wrote:
>
https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
> File content/browser/indexed_db/leveldb/leveldb_database.cc (right):
> 
>
https://codereview.chromium.org/472573003/diff/1/content/browser/indexed_db/l...
> content/browser/indexed_db/leveldb/leveldb_database.cc:289:
> UMA_HISTOGRAM_MEDIUM_TIMES("WebCore.IndexedDB.LevelDB.OpenTime.Disk",
> On 2014/08/13 23:53:02, cmumford wrote:
> > On 2014/08/13 22:49:11, jsbell wrote:
> > > Assumes anything < 10 seconds is "fast enough" and we don't need to break
it
> > > down further? Sounds okay.
> > 
> > If I'm reading the code correctly then UMA_HISTOGRAM_MEDIUM_TIMES is 10msec
<
> h
> > < 3min. I'm not sure if times < 10msec are ignored, or rounded up to to
> 10msec.
> 
> They'll show up in the 0 bucket.

Oops, yeah, I meant < 10ms.

That's probably right on the edge for "fast enough" but since the current
complaints are about cases when it's 10x-500x slower than that (i.e. 100ms to
5s) I think 10ms granularity is fine.

[jsbell, 2014-08-14 00:20:19]

I see Get() isn't measured either, sorry. I don't think we need to measure it
and Remove(), it just (from the code review tool) looked like only Remove() was
left out before. I'm fine with whatever. :)

lgtm - you'll want to get isherman@ to review the histograms change.

[cmumford, 2014-08-14 17:11:35]

Adding isherman for review of tools/metrics/histograms/histograms.xml

P.S. I will tackle the "total open/blocked/upgrade" histogram measurement in a
separate CL.

[Ilya Sherman, 2014-08-14 20:52:12]

Histograms LGTM % nits.

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35749: +<histogram
name="WebCore.IndexedDB.LevelDB.OpenTime.Disk" units="milliseconds">
nit: Why does this histogram have a ".Disk" suffix, whereas the others you're
adding do not?  Is this an important distinction?

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35768: +    The time that it takes to
commit an IndexedDB transaction to it's LevelDB
nit: "it's" -> "its"

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35776: +    The time that it takes to
write data to a IndexedDB LevelDB backing store.
nit: "a" -> "an".

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35776: +    The time that it takes to
write data to a IndexedDB LevelDB backing store.
nit: "IndexedDB" -> "IndexedDB's"?

[cmumford, 2014-08-14 21:58:38]

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35749: +<histogram
name="WebCore.IndexedDB.LevelDB.OpenTime.Disk" units="milliseconds">
On 2014/08/14 20:52:11, Ilya Sherman wrote:
> nit: Why does this histogram have a ".Disk" suffix, whereas the others you're
> adding do not?  Is this an important distinction?

Good question. We also open up IDB's in memory - for incognito windows.

I just consulted jsbell and have removed ".Disk"

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35768: +    The time that it takes to
commit an IndexedDB transaction to it's LevelDB
On 2014/08/14 20:52:11, Ilya Sherman wrote:
> nit: "it's" -> "its"

Done.

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35776: +    The time that it takes to
write data to a IndexedDB LevelDB backing store.
On 2014/08/14 20:52:12, Ilya Sherman wrote:
> nit: "IndexedDB" -> "IndexedDB's"?

Done.

https://codereview.chromium.org/472573003/diff/40001/tools/metrics/histograms...
tools/metrics/histograms/histograms.xml:35776: +    The time that it takes to
write data to a IndexedDB LevelDB backing store.
On 2014/08/14 20:52:12, Ilya Sherman wrote:
> nit: "IndexedDB" -> "IndexedDB's"?

Done.

[cmumford, 2014-08-14 21:58:50]

The CQ bit was checked by cmumford@chromium.org

[commit-bot: I haz the power, 2014-08-14 22:01:07]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/cmumford@chromium.org/472573003/80001

[commit-bot: I haz the power, 2014-08-15 04:04:42]

FYI, CQ is re-trying this CL (attempt #1).
The failing builders are:
  android_dbg_triggered_tests on tryserver.chromium.linux
(http://build.chromium.org/p/tryserver.chromium.linux/builders/android_dbg_tri...)
  linux_chromium_chromeos_rel_swarming on tryserver.chromium.linux
(http://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_...)

[commit-bot: I haz the power, 2014-08-15 06:35:19]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2014-08-15 06:35:21]

Try jobs failed on following builders:
  android_dbg_triggered_tests on tryserver.chromium.linux
(http://build.chromium.org/p/tryserver.chromium.linux/builders/android_dbg_tri...)

[cmumford, 2014-08-15 14:57:09]

The CQ bit was checked by cmumford@chromium.org

[commit-bot: I haz the power, 2014-08-15 14:59:43]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/cmumford@chromium.org/472573003/80001

[commit-bot: I haz the power, 2014-08-15 16:12:49]

Committed patchset #5 (80001) as 289895