|
|
Description[Storage] Blob Storage perf tests
BUG=489799
CQ_EXTRA_TRYBOTS=tryserver.chromium.perf:linux_perf_bisect;tryserver.chromium.perf:mac_perf_bisect;tryserver.chromium.perf:win_perf_bisect;tryserver.chromium.perf:android_nexus5_perf_bisect
Committed: https://crrev.com/dbd2315e79df68af221c06dadbc00adfcdef07df
Cr-Commit-Position: refs/heads/master@{#332541}
Patch Set 1 #Patch Set 2 : page set update #Patch Set 3 : PageSet update #Patch Set 4 : Next iter #Patch Set 5 : Added metric to timeline metrics #Patch Set 6 : Whoops, forgot timeline metric #
Total comments: 1
Patch Set 7 : Partly working! #
Total comments: 2
Patch Set 8 : Added test names #Patch Set 9 : Added read stats #
Total comments: 18
Patch Set 10 : Fixes and metric unittest #
Total comments: 21
Patch Set 11 : comments #Patch Set 12 : fixes #
Total comments: 10
Patch Set 13 : comments, and using thread_duration #
Total comments: 2
Patch Set 14 : Removed reliance on Interactions in metric #
Total comments: 7
Patch Set 15 : UUID-based reads, updated tests #
Total comments: 2
Patch Set 16 : None case, filter nones #Patch Set 17 : copyright fix #Messages
Total messages: 58 (8 generated)
nednguyen@google.com changed reviewers: + nednguyen@google.com
https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... File tools/perf/benchmarks/blob_storage.py (right): https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:18: TOPLEVEL_CATEGORY) My guess is this category filter confused telemetry trace parsing code :-) For a speculative workaround, can you change those two lines to: cat_filter = tracing_category_filter.TracingCategoryFilter.CreateNoOverheadFilter() cat_filter.AddIncludedCategory(TOPLEVEL_CATEGORY) and see if it works?
That worked, thanks! Next problem that I'm having: For some reason telemetry isn't reading some of my traces. Specifically, the "BlobRequest" trace. This is present in the 0.html file (as you can see), but it doesn't show up in the trace events. Does telemetry perhaps not support the 'async' trace events in the timeline? You can see these events definitely fall within the "Action_ReadBlob" interaction below. Thanks so much! Daniel On Thu, May 7, 2015 at 3:51 AM <nednguyen@google.com> wrote: > > > https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... > File tools/perf/benchmarks/blob_storage.py (right): > > > https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... > tools/perf/benchmarks/blob_storage.py:18 > <https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/...>: > TOPLEVEL_CATEGORY) > My guess is this category filter confused telemetry trace parsing code > :-) > > For a speculative workaround, can you change those two lines to: > cat_filter = > tracing_category_filter.TracingCategoryFilter.CreateNoOverheadFilter() > cat_filter.AddIncludedCategory(TOPLEVEL_CATEGORY) > > and see if it works? > > https://codereview.chromium.org/1104053006/ > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
On 2015/05/07 at 20:59:20, chromium-reviews wrote: > That worked, thanks! > > Next problem that I'm having: > > For some reason telemetry isn't reading some of my traces. Specifically, > the "BlobRequest" trace. This is present in the 0.html file (as you can > see), but it doesn't show up in the trace events. Does telemetry perhaps > not support the 'async' trace events in the timeline? > > You can see these events definitely fall within the "Action_ReadBlob" > interaction below. > > Thanks so much! > Daniel > > On Thu, May 7, 2015 at 3:51 AM <nednguyen@google.com> wrote: > > > > > > > https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... > > File tools/perf/benchmarks/blob_storage.py (right): > > > > > > https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... > > tools/perf/benchmarks/blob_storage.py:18 > > <https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/...>: > > TOPLEVEL_CATEGORY) > > My guess is this category filter confused telemetry trace parsing code > > :-) > > > > For a speculative workaround, can you change those two lines to: > > cat_filter = > > tracing_category_filter.TracingCategoryFilter.CreateNoOverheadFilter() > > cat_filter.AddIncludedCategory(TOPLEVEL_CATEGORY) > > > > and see if it works? > > > > https://codereview.chromium.org/1104053006/ > > > > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org. > Also, should I move this back to the main thread? Or should we keep discussion here now?
https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), Instead of IterAllSlices(), try IterAllEvents instead. Async event is not slice, I think
We can keep going on this. I think this is close to be land-able. It would be great if you let others on the original thread know that we have resolved the issue and will keep the discussion in code review so they don't spend more time there :) On Thu, May 7, 2015, 3:50 PM <dmurph@chromium.org> wrote: > Reviewers: nednguyen (ooo til 05-07), > > Message: > On 2015/05/07 at 20:59:20, chromium-reviews wrote: > > That worked, thanks! > > > Next problem that I'm having: > > > For some reason telemetry isn't reading some of my traces. Specifically, > > the "BlobRequest" trace. This is present in the 0.html file (as you can > > see), but it doesn't show up in the trace events. Does telemetry perhaps > > not support the 'async' trace events in the timeline? > > > You can see these events definitely fall within the "Action_ReadBlob" > > interaction below. > > > Thanks so much! > > Daniel > > > On Thu, May 7, 2015 at 3:51 AM <nednguyen@google.com> wrote: > > > > > > > > > > > > https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... > > > File tools/perf/benchmarks/blob_storage.py (right): > > > > > > > > > > > https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... > > > tools/perf/benchmarks/blob_storage.py:18 > > > > < > https://codereview.chromium.org/1104053006/diff/100001/tools/perf/benchmarks/... > >: > > > TOPLEVEL_CATEGORY) > > > My guess is this category filter confused telemetry trace parsing code > > > :-) > > > > > > For a speculative workaround, can you change those two lines to: > > > cat_filter = > > > tracing_category_filter.TracingCategoryFilter.CreateNoOverheadFilter() > > > cat_filter.AddIncludedCategory(TOPLEVEL_CATEGORY) > > > > > > and see if it works? > > > > > > https://codereview.chromium.org/1104053006/ > > > > > > To unsubscribe from this group and stop receiving emails from it, send an > email to chromium-reviews+unsubscribe@chromium.org. > > > Also, should I move this back to the main thread? Or should we keep > discussion > here now? > > Description: > [Storage] Blob Storage perf tests > > BUG= > > CQ_EXTRA_TRYBOTS=tryserver.chromium.perf:linux_perf_bisect;tryserver.chromium.perf:mac_perf_bisect;tryserver.chromium.perf:win_perf_bisect;tryserver.chromium.perf:android_nexus5_perf_bisect > > Please review this at https://codereview.chromium.org/1104053006/ > > Base URL: https://chromium.googlesource.com/chromium/src.git@master > > Affected files (+276, -2 lines): > M storage/browser/blob/blob_url_request_job.cc > A tools/perf/benchmarks/blob_storage.py > A tools/perf/page_sets/blob/blob-workshop.html > A tools/perf/page_sets/blob_workshop.py > A tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py > M tools/telemetry/telemetry/web_perf/timeline_based_measurement.py > > > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
any more ideas? I printed out every event name that I get and no "BlobRequest" events are in there. https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), On 2015/05/08 01:35:12, nednguyen wrote: > Instead of IterAllSlices(), try IterAllEvents instead. Async event is not slice, > I think Hm, still doesn't work :'(
On 2015/05/08 18:59:23, dmurph wrote: > any more ideas? I printed out every event name that I get and no "BlobRequest" > events are in there. Then I think this is definitely a trace parsing issue. I will try to patch this and run in on my machine. > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: > self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), > On 2015/05/08 01:35:12, nednguyen wrote: > > Instead of IterAllSlices(), try IterAllEvents instead. Async event is not > slice, > > I think > > Hm, still doesn't work :'(
On 2015/05/08 19:28:48, nednguyen wrote: > On 2015/05/08 18:59:23, dmurph wrote: > > any more ideas? I printed out every event name that I get and no > "BlobRequest" > > events are in there. > Then I think this is definitely a trace parsing issue. I will try to patch this > and run in on my machine. > > > > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > > > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: > > self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), > > On 2015/05/08 01:35:12, nednguyen wrote: > > > Instead of IterAllSlices(), try IterAllEvents instead. Async event is not > > slice, > > > I think > > > > Hm, still doesn't work :'( Hmh, when I run this on my local machine, it works. An example output: ./tools/perf/run_benchmark blob_storage.blob_storage --browser=release [ RUN ] blob-workshop.html [ OK ] blob-workshop.html (11949 ms) [ RUN ] blob-workshop.html [ OK ] blob-workshop.html (11530 ms) [ PASSED ] 2 tests. Pages: [blob-workshop.html,blob-workshop.html] RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000] ms Avg Action_CreateBlob-blob_writes_2Bx200: 0.030445ms Sd Action_CreateBlob-blob_writes_2Bx200: 0.012047ms RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= [0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] ms Avg Action_CreateBlob-blob_writes_2Bx200: 0.029760ms Sd Action_CreateBlob-blob_writes_2Bx200: 0.010594ms *RESULT Action_CreateBlob-blob_writes_2Bx200: Action_CreateBlob-blob_writes_2Bx200= [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000,0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] ms Avg Action_CreateBlob-blob_writes_2Bx200: 0.030103ms Sd Action_CreateBlob-blob_writes_2Bx200: 0.011335ms RESULT telemetry_page_measurement_results: num_failed= 0 count RESULT telemetry_page_measurement_results: num_errored= 0 count
Right, there are no "blob_reads". Only the writes. If you print out every event, you never see the "BlobRequest" event. However, if you look at the trace, it's there. On Fri, May 8, 2015 at 2:35 PM <nednguyen@google.com> wrote: > On 2015/05/08 19:28:48, nednguyen wrote: > > On 2015/05/08 18:59:23, dmurph wrote: > > > any more ideas? I printed out every event name that I get and no > > "BlobRequest" > > > events are in there. > > Then I think this is definitely a trace parsing issue. I will try to > patch > this > > and run in on my machine. > > > > > > > > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > > > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py > > (right): > > > > > > > > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: > > > self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), > > > On 2015/05/08 01:35:12, nednguyen wrote: > > > > Instead of IterAllSlices(), try IterAllEvents instead. Async event is > > not > > > slice, > > > > I think > > > > > > Hm, still doesn't work :'( > > Hmh, when I run this on my local machine, it works. An example output: > > ./tools/perf/run_benchmark blob_storage.blob_storage --browser=release > [ RUN ] blob-workshop.html > [ OK ] blob-workshop.html (11949 ms) > [ RUN ] blob-workshop.html > [ OK ] blob-workshop.html (11530 ms) > [ PASSED ] 2 tests. > > Pages: [blob-workshop.html,blob-workshop.html] > RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= > > [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000] > ms > Avg Action_CreateBlob-blob_writes_2Bx200: 0.030445ms > Sd Action_CreateBlob-blob_writes_2Bx200: 0.012047ms > RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= > > [0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] > ms > Avg Action_CreateBlob-blob_writes_2Bx200: 0.029760ms > Sd Action_CreateBlob-blob_writes_2Bx200: 0.010594ms > *RESULT Action_CreateBlob-blob_writes_2Bx200: > Action_CreateBlob-blob_writes_2Bx200= > > [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000,0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] > ms > Avg Action_CreateBlob-blob_writes_2Bx200: 0.030103ms > Sd Action_CreateBlob-blob_writes_2Bx200: 0.011335ms > RESULT telemetry_page_measurement_results: num_failed= 0 count > RESULT telemetry_page_measurement_results: num_errored= 0 count > > > https://codereview.chromium.org/1104053006/ > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
Whoops, replying with @chromium Right, there are no "blob_reads". Only the writes. If you print out every event, you never see the "BlobRequest" event. However, if you look at the trace, it's there. (you can comment out all be the user story to make the run go faster) Daniel On Fri, May 8, 2015 at 2:35 PM <nednguyen@google.com> wrote: > On 2015/05/08 19:28:48, nednguyen wrote: > > On 2015/05/08 18:59:23, dmurph wrote: > > > any more ideas? I printed out every event name that I get and no > > "BlobRequest" > > > events are in there. > > Then I think this is definitely a trace parsing issue. I will try to > patch > this > > and run in on my machine. > > > > > > > > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > > > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py > > (right): > > > > > > > > > https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... > > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: > > > self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), > > > On 2015/05/08 01:35:12, nednguyen wrote: > > > > Instead of IterAllSlices(), try IterAllEvents instead. Async event is > > not > > > slice, > > > > I think > > > > > > Hm, still doesn't work :'( > > Hmh, when I run this on my local machine, it works. An example output: > > ./tools/perf/run_benchmark blob_storage.blob_storage --browser=release > [ RUN ] blob-workshop.html > [ OK ] blob-workshop.html (11949 ms) > [ RUN ] blob-workshop.html > [ OK ] blob-workshop.html (11530 ms) > [ PASSED ] 2 tests. > > Pages: [blob-workshop.html,blob-workshop.html] > RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= > > [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000] > ms > Avg Action_CreateBlob-blob_writes_2Bx200: 0.030445ms > Sd Action_CreateBlob-blob_writes_2Bx200: 0.012047ms > RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= > > [0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] > ms > Avg Action_CreateBlob-blob_writes_2Bx200: 0.029760ms > Sd Action_CreateBlob-blob_writes_2Bx200: 0.010594ms > *RESULT Action_CreateBlob-blob_writes_2Bx200: > Action_CreateBlob-blob_writes_2Bx200= > > [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000,0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] > ms > Avg Action_CreateBlob-blob_writes_2Bx200: 0.030103ms > Sd Action_CreateBlob-blob_writes_2Bx200: 0.011335ms > RESULT telemetry_page_measurement_results: num_failed= 0 count > RESULT telemetry_page_measurement_results: num_errored= 0 count > > > https://codereview.chromium.org/1104053006/ > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
I actually don't find BlobRequest in the trace-viewer either, only Registry::RegisterBlob On Fri, May 8, 2015 at 2:38 PM Daniel Murphy <dmurph@chromium.org> wrote: > Whoops, replying with @chromium > > Right, there are no "blob_reads". Only the writes. > > If you print out every event, you never see the "BlobRequest" event. > However, if you look at the trace, it's there. > > (you can comment out all be the user story to make the run go faster) > > Daniel > On Fri, May 8, 2015 at 2:35 PM <nednguyen@google.com> wrote: > >> On 2015/05/08 19:28:48, nednguyen wrote: >> > On 2015/05/08 18:59:23, dmurph wrote: >> > > any more ideas? I printed out every event name that I get and no >> > "BlobRequest" >> > > events are in there. >> > Then I think this is definitely a trace parsing issue. I will try to >> patch >> this >> > and run in on my machine. >> > > >> > > >> >> >> https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... >> > > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py >> > (right): >> > > >> > > >> >> >> https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... >> > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: >> > > self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), >> > > On 2015/05/08 01:35:12, nednguyen wrote: >> > > > Instead of IterAllSlices(), try IterAllEvents instead. Async event >> is >> > not >> > > slice, >> > > > I think >> > > >> > > Hm, still doesn't work :'( >> >> Hmh, when I run this on my local machine, it works. An example output: >> >> ./tools/perf/run_benchmark blob_storage.blob_storage --browser=release >> [ RUN ] blob-workshop.html >> [ OK ] blob-workshop.html (11949 ms) >> [ RUN ] blob-workshop.html >> [ OK ] blob-workshop.html (11530 ms) >> [ PASSED ] 2 tests. >> >> Pages: [blob-workshop.html,blob-workshop.html] >> RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= >> >> [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000] >> ms >> Avg Action_CreateBlob-blob_writes_2Bx200: 0.030445ms >> Sd Action_CreateBlob-blob_writes_2Bx200: 0.012047ms >> RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= >> >> [0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] >> ms >> Avg Action_CreateBlob-blob_writes_2Bx200: 0.029760ms >> Sd Action_CreateBlob-blob_writes_2Bx200: 0.010594ms >> *RESULT Action_CreateBlob-blob_writes_2Bx200: >> Action_CreateBlob-blob_writes_2Bx200= >> >> [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000,0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] >> ms >> Avg Action_CreateBlob-blob_writes_2Bx200: 0.030103ms >> Sd Action_CreateBlob-blob_writes_2Bx200: 0.011335ms >> RESULT telemetry_page_measurement_results: num_failed= 0 count >> RESULT telemetry_page_measurement_results: num_errored= 0 count >> >> >> https://codereview.chromium.org/1104053006/ >> > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
Did you do a full build of Chrome? The patch fixes a bug where that wasn't showing up. You should at least see BlobRequest::CountSize On Fri, May 8, 2015 at 3:04 PM Ned <nednguyen@google.com> wrote: > I actually don't find BlobRequest in the trace-viewer either, only > Registry::RegisterBlob > > On Fri, May 8, 2015 at 2:38 PM Daniel Murphy <dmurph@chromium.org> wrote: > >> Whoops, replying with @chromium >> >> Right, there are no "blob_reads". Only the writes. >> >> If you print out every event, you never see the "BlobRequest" event. >> However, if you look at the trace, it's there. >> >> (you can comment out all be the user story to make the run go faster) >> >> Daniel >> On Fri, May 8, 2015 at 2:35 PM <nednguyen@google.com> wrote: >> >>> On 2015/05/08 19:28:48, nednguyen wrote: >>> > On 2015/05/08 18:59:23, dmurph wrote: >>> > > any more ideas? I printed out every event name that I get and no >>> > "BlobRequest" >>> > > events are in there. >>> > Then I think this is definitely a trace parsing issue. I will try to >>> patch >>> this >>> > and run in on my machine. >>> > > >>> > > >>> >>> >>> https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... >>> > > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py >>> > (right): >>> > > >>> > > >>> >>> >>> https://codereview.chromium.org/1104053006/diff/120001/tools/telemetry/teleme... >>> > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:24: >>> > > self._AddResultsInternal(renderer_thread.parent.IterAllSlices(), >>> > > On 2015/05/08 01:35:12, nednguyen wrote: >>> > > > Instead of IterAllSlices(), try IterAllEvents instead. Async event >>> is >>> > not >>> > > slice, >>> > > > I think >>> > > >>> > > Hm, still doesn't work :'( >>> >>> Hmh, when I run this on my local machine, it works. An example output: >>> >>> ./tools/perf/run_benchmark blob_storage.blob_storage --browser=release >>> [ RUN ] blob-workshop.html >>> [ OK ] blob-workshop.html (11949 ms) >>> [ RUN ] blob-workshop.html >>> [ OK ] blob-workshop.html (11530 ms) >>> [ PASSED ] 2 tests. >>> >>> Pages: [blob-workshop.html,blob-workshop.html] >>> RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= >>> >>> [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000] >>> ms >>> Avg Action_CreateBlob-blob_writes_2Bx200: 0.030445ms >>> Sd Action_CreateBlob-blob_writes_2Bx200: 0.012047ms >>> RESULT Action_CreateBlob-blob_writes_2Bx200: blob-workshop.html= >>> >>> [0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] >>> ms >>> Avg Action_CreateBlob-blob_writes_2Bx200: 0.029760ms >>> Sd Action_CreateBlob-blob_writes_2Bx200: 0.010594ms >>> *RESULT Action_CreateBlob-blob_writes_2Bx200: >>> Action_CreateBlob-blob_writes_2Bx200= >>> >>> [0.052000,0.052000,0.075000,0.019000,0.017000,0.017000,0.019000,0.020000,0.020000,0.019000,0.022000,0.020000,0.020000,0.019000,0.033000,0.036000,0.040000,0.044000,0.042000,0.042000,0.038000,0.042000,0.058000,0.032000,0.025000,0.039000,0.035000,0.031000,0.030000,0.030000,0.031000,0.014000,0.041000,0.031000,0.033000,0.023000,0.041000,0.042000,0.041000,0.041000,0.036000,0.035000,0.037000,0.042000,0.048000,0.033000,0.030000,0.031000,0.051000,0.028000,0.035000,0.032000,0.027000,0.027000,0.020000,0.015000,0.015000,0.016000,0.016000,0.015000,0.019000,0.014000,0.014000,0.018000,0.015000,0.015000,0.014000,0.026000,0.024000,0.024000,0.037000,0.036000,0.037000,0.037000,0.037000,0.026000,0.039000,0.036000,0.036000,0.037000,0.046000,0.038000,0.029000,0.045000,0.017000,0.021000,0.036000,0.029000,0.030000,0.028000,0.047000,0.031000,0.031000,0.030000,0.023000,0.014000,0.015000,0.014000,0.013000,0.015000,0.014000,0.013000,0.014000,0.013000,0.014000,0.014000,0.013000,0.014000,0.014000,0.037000,0.042000,0.051000,0.039000,0.042000,0.043000,0.016000,0.017000,0.016000,0.019000,0.016000,0.015000,0.038000,0.038000,0.016000,0.041000,0.032000,0.020000,0.017000,0.017000,0.016000,0.016000,0.017000,0.016000,0.016000,0.016000,0.024000,0.029000,0.032000,0.038000,0.034000,0.037000,0.031000,0.029000,0.033000,0.035000,0.032000,0.034000,0.033000,0.033000,0.032000,0.051000,0.041000,0.040000,0.042000,0.020000,0.014000,0.016000,0.015000,0.025000,0.034000,0.024000,0.015000,0.046000,0.038000,0.030000,0.053000,0.030000,0.031000,0.038000,0.040000,0.040000,0.041000,0.039000,0.038000,0.039000,0.038000,0.041000,0.039000,0.042000,0.042000,0.081000,0.044000,0.024000,0.029000,0.033000,0.023000,0.043000,0.034000,0.044000,0.028000,0.028000,0.033000,0.035000,0.027000,0.029000,0.051000,0.042000,0.044000,0.045000,0.044000,0.035000,0.022000,0.015000,0.028000,0.021000,0.014000,0.016000,0.021000,0.015000,0.014000,0.015000,0.015000,0.046000,0.039000,0.037000,0.040000,0.045000,0.039000,0.041000,0.038000,0.030000,0.020000,0.022000,0.029000,0.031000,0.038000,0.048000,0.051000,0.037000,0.040000,0.033000,0.037000,0.026000,0.034000,0.032000,0.039000,0.056000,0.066000,0.039000,0.037000,0.036000,0.033000,0.037000,0.041000,0.030000,0.031000,0.043000,0.035000,0.023000,0.033000,0.022000,0.029000,0.027000,0.022000,0.020000,0.023000,0.022000,0.021000,0.032000,0.023000,0.021000,0.014000,0.033000,0.030000,0.028000,0.030000,0.028000,0.028000,0.029000,0.027000,0.027000,0.035000,0.031000,0.034000,0.030000,0.017000,0.042000,0.049000,0.023000,0.025000,0.024000,0.019000,0.020000,0.029000,0.026000,0.018000,0.024000,0.017000,0.017000,0.019000,0.017000,0.023000,0.024000,0.020000,0.025000,0.026000,0.022000,0.025000,0.024000,0.024000,0.044000,0.041000,0.056000,0.085000,0.033000,0.030000,0.033000,0.027000,0.023000,0.029000,0.020000,0.017000,0.024000,0.019000,0.019000,0.046000,0.027000,0.025000,0.026000,0.025000,0.026000,0.039000,0.017000,0.015000,0.015000,0.014000,0.015000,0.015000,0.026000,0.035000,0.039000,0.030000,0.027000,0.028000,0.025000,0.038000,0.037000,0.035000,0.036000,0.028000,0.028000,0.035000,0.022000,0.020000,0.036000,0.034000,0.021000,0.022000,0.026000,0.024000,0.023000,0.024000,0.022000,0.047000,0.042000,0.044000,0.044000,0.042000,0.037000,0.038000,0.039000,0.041000,0.046000,0.042000,0.047000,0.045000,0.039000,0.051000,0.041000,0.048000,0.041000,0.021000,0.025000,0.021000,0.025000,0.022000,0.026000,0.026000,0.025000,0.025000,0.025000,0.020000,0.018000,0.021000,0.022000,0.022000,0.020000,0.019000,0.022000,0.021000,0.018000,0.021000,0.021000,0.039000,0.038000,0.036000,0.039000,0.037000,0.038000,0.031000] >>> ms >>> Avg Action_CreateBlob-blob_writes_2Bx200: 0.030103ms >>> Sd Action_CreateBlob-blob_writes_2Bx200: 0.011335ms >>> RESULT telemetry_page_measurement_results: num_failed= 0 count >>> RESULT telemetry_page_measurement_results: num_errored= 0 count >>> >>> >>> https://codereview.chromium.org/1104053006/ >>> >> To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
I confirm that I see those events in trace.json. I will work on the trace parser code to make sure that telemetry can read those events.
On 2015/05/11 16:05:53, nednguyen (slow review) wrote: > I confirm that I see those events in trace.json. I will work on the trace parser > code to make sure that telemetry can read those events. The code of parsing the 'BlobRequest' work fine. However, I found that process id of 'Registry::RegisterBlob' events are different from that of 'BlobRequest' event. So the core bugs here that the renderer_thread object passed into AddResults method represents the same thread as interaction records (which has the same process with 'Registry::RegisterBlob' but not 'BlobRequest' events. Looks like Registry::RegisterBlob are in renderer process, whereas BlobRequest are in browser process.
On 2015/05/11 at 16:34:51, nednguyen wrote: > On 2015/05/11 16:05:53, nednguyen (slow review) wrote: > > I confirm that I see those events in trace.json. I will work on the trace parser > > code to make sure that telemetry can read those events. > > The code of parsing the 'BlobRequest' work fine. > However, I found that process id of 'Registry::RegisterBlob' events are different from that of 'BlobRequest' event. So the core bugs here that the renderer_thread object passed into AddResults method represents the same thread as interaction records (which has the same process with 'Registry::RegisterBlob' but not 'BlobRequest' events. > > Looks like Registry::RegisterBlob are in renderer process, whereas BlobRequest are in browser process. Ah! Yeah I should have realized that might have been the problem. Is there any easy way to grab those events?
On 2015/05/14 03:55:13, dmurph wrote: > On 2015/05/11 at 16:34:51, nednguyen wrote: > > On 2015/05/11 16:05:53, nednguyen (slow review) wrote: > > > I confirm that I see those events in trace.json. I will work on the trace > parser > > > code to make sure that telemetry can read those events. > > > > The code of parsing the 'BlobRequest' work fine. > > However, I found that process id of 'Registry::RegisterBlob' events are > different from that of 'BlobRequest' event. So the core bugs here that the > renderer_thread object passed into AddResults method represents the same thread > as interaction records (which has the same process with 'Registry::RegisterBlob' > but not 'BlobRequest' events. > > > > Looks like Registry::RegisterBlob are in renderer process, whereas BlobRequest > are in browser process. > > Ah! Yeah I should have realized that might have been the problem. Is there any > easy way to grab those events? Hi Ben, I already cc you in https://code.google.com/p/chromium/issues/detail?id=465416. The current model of dispatching renderer thread alongs with interaction records in those threads to these timeline based metrics is faulty. These timeline based metrics AddResults method should just need to do the work on computing the metrics on the right threads/processes themselves. I think the quickest fix for you know is adding an assert that there is only single renderer process in the model, then pull out BlobRequest events in doing st like: browser_process = [p for p in model.process and p.name == "Browser"][0]
On 2015/05/14 at 16:45:11, nednguyen wrote: > On 2015/05/14 03:55:13, dmurph wrote: > > On 2015/05/11 at 16:34:51, nednguyen wrote: > > > On 2015/05/11 16:05:53, nednguyen (slow review) wrote: > > > > I confirm that I see those events in trace.json. I will work on the trace > > parser > > > > code to make sure that telemetry can read those events. > > > > > > The code of parsing the 'BlobRequest' work fine. > > > However, I found that process id of 'Registry::RegisterBlob' events are > > different from that of 'BlobRequest' event. So the core bugs here that the > > renderer_thread object passed into AddResults method represents the same thread > > as interaction records (which has the same process with 'Registry::RegisterBlob' > > but not 'BlobRequest' events. > > > > > > Looks like Registry::RegisterBlob are in renderer process, whereas BlobRequest > > are in browser process. > > > > Ah! Yeah I should have realized that might have been the problem. Is there any > > easy way to grab those events? > > Hi Ben, I already cc you in https://code.google.com/p/chromium/issues/detail?id=465416. The current model of dispatching renderer thread alongs with interaction records in those threads to these timeline based metrics is faulty. These timeline based metrics AddResults method should just need to do the work on computing the metrics on the right threads/processes themselves. > > I think the quickest fix for you know is adding an assert that there is only single renderer process in the model, then pull out BlobRequest events in doing st like: > browser_process = [p for p in model.process and p.name == "Browser"][0] Thanks! Done. WDYT? - Daniel
https://codereview.chromium.org/1104053006/diff/160001/tools/perf/benchmarks/... File tools/perf/benchmarks/blob_storage.py (right): https://codereview.chromium.org/1104053006/diff/160001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:11: nit: add another blank line https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... File tools/perf/page_sets/blob_workshop.py (right): https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:7: ditto https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:10: super(BlobWorkshopPage, self).__init__(url='file://blob/blob-workshop.html', page_set=page_set) You may want to define the 'name' for these pages, otherwise I worry that all pages in the page_sets end up having the same name. https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:11: self.blob_sizes = blob_sizes Make this and the other 3 field members private https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:18: url, script_to_evaluate_on_commit=self.script_to_evaluate_on_commit) 3 lines above can be removed and you can use put the rest of this method in RunPageInteractions https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:37: if (errors): unnecessary parens https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:22: def AddResults(self, model, renderer_thread, interactions, results): Can you add unittest for this? You can look at telemetry/web_perf/metrics/smoothness_unittest for example https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:35: self._AddResultsInternal(events, interactions, results) If you don't add the assertion that there is only single renderer thread, then this will get executed multiple times.
https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:35: self._AddResultsInternal(events, interactions, results) On 2015/05/18 22:55:54, nednguyen wrote: > If you don't add the assertion that there is only single renderer thread, then > this will get executed multiple times. Err, silly. This isn't true. Please ignore this comment. :P https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:51: name='blob_reads_' + page.write_method + '_' + page.read_method, No, you would want the name to be static. And timeline based metrics cannot make any assumption about the pages' properties
On 2015/05/19 00:34:16, nednguyen wrote: > https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:35: > self._AddResultsInternal(events, interactions, results) > On 2015/05/18 22:55:54, nednguyen wrote: > > If you don't add the assertion that there is only single renderer thread, then > > this will get executed multiple times. > > Err, silly. This isn't true. Please ignore this comment. :P > > https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:51: > name='blob_reads_' + page.write_method + '_' + page.read_method, > No, you would want the name to be static. And timeline based metrics cannot make > any assumption about the pages' properties Also I forgot to mention, if you intend to actually land this patch, can you file a bug about this, and add some information about how these metrics would help catching a particular kind of regression that you care about?
It's working yay! Bug here: https://code.google.com/p/chromium/issues/detail?id=489799 +kinuko for storage/browser/blob/blob_url_request_job.cc https://codereview.chromium.org/1104053006/diff/160001/tools/perf/benchmarks/... File tools/perf/benchmarks/blob_storage.py (right): https://codereview.chromium.org/1104053006/diff/160001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:11: On 2015/05/18 at 22:55:53, nednguyen wrote: > nit: add another blank line Done. https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... File tools/perf/page_sets/blob_workshop.py (right): https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:7: On 2015/05/18 at 22:55:54, nednguyen wrote: > ditto Done. https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:10: super(BlobWorkshopPage, self).__init__(url='file://blob/blob-workshop.html', page_set=page_set) On 2015/05/18 at 22:55:54, nednguyen wrote: > You may want to define the 'name' for these pages, otherwise I worry that all pages in the page_sets end up having the same name. Done. https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:11: self.blob_sizes = blob_sizes On 2015/05/18 at 22:55:54, nednguyen wrote: > Make this and the other 3 field members private Done. https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:18: url, script_to_evaluate_on_commit=self.script_to_evaluate_on_commit) On 2015/05/18 at 22:55:54, nednguyen wrote: > 3 lines above can be removed and you can use put the rest of this method in RunPageInteractions Done. https://codereview.chromium.org/1104053006/diff/160001/tools/perf/page_sets/b... tools/perf/page_sets/blob_workshop.py:37: if (errors): On 2015/05/18 at 22:55:54, nednguyen wrote: > unnecessary parens Done. https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:22: def AddResults(self, model, renderer_thread, interactions, results): On 2015/05/18 at 22:55:54, nednguyen wrote: > Can you add unittest for this? You can look at telemetry/web_perf/metrics/smoothness_unittest for example Done. https://codereview.chromium.org/1104053006/diff/160001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:51: name='blob_reads_' + page.write_method + '_' + page.read_method, On 2015/05/19 at 00:34:15, nednguyen wrote: > No, you would want the name to be static. And timeline based metrics cannot make any assumption about the pages' properties Done.
nednguyen@google.com changed reviewers: + eakuefner@chromium.org
Ethan: you want to take a pass at reviewing this?
looking good; some notes, mostly style stuff. https://codereview.chromium.org/1104053006/diff/180001/tools/perf/benchmarks/... File tools/perf/benchmarks/blob_storage.py (right): https://codereview.chromium.org/1104053006/diff/180001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:10: TOPLEVEL_CATEGORY = 'Blob' I think you can group constant definitions together, but a newline above this would be good. I view a group of constant definitions as sort of "one top-level definition" https://codereview.chromium.org/1104053006/diff/180001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:14: """Timeline based measurement benchmark for Blob Storage.""" nit: newline after https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:9: nit: two newlines between top-level definitions. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:17: """ nit: extra newline after docstring. also, can you please make this docstring google-style? https://google-styleguide.googlecode.com/svn/trunk/pyguide.html?showone=Comme... https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:18: WRITE_INTERACTION_LABEL = 'Action_CreateBlob' Please move these constants above, out of the class. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:36: browser_process = \ nit: backslash 1. should not be necessary here since python allows whitespace inside of (),[],{} and 2. is against styleguide. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:42: event_predicate=self._WriteEventPredicate): I don't think this is going to work: event_predicate is supposed to take an event and return a bool, but your predicates are instance methods. I think inlining them would be best, and you can use newlines if it won't fit onto one line. eg: event_predicate=(lambda e: e.name == WRITE_INTERACTION_LABEL) (pursuant to moving the events out of the class as i mentioned above) https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:90: for event in [e for e in events \ no backslash here either https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py (right): https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py:20: blob_timeline.BlobTimelineMetric()._AddWriteResultsInternal( I think it would be best to test the public behavior if you can here. As a last resort add a # pylint: disable=protected-access. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py:24: return dict((value.name, value.values) for value in Please call results.DidRunPage above this line.
Done w/ a couple questions https://codereview.chromium.org/1104053006/diff/180001/tools/perf/benchmarks/... File tools/perf/benchmarks/blob_storage.py (right): https://codereview.chromium.org/1104053006/diff/180001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:10: TOPLEVEL_CATEGORY = 'Blob' On 2015/05/22 at 18:33:18, eakuefner wrote: > I think you can group constant definitions together, but a newline above this would be good. I view a group of constant definitions as sort of "one top-level definition" Done. https://codereview.chromium.org/1104053006/diff/180001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:14: """Timeline based measurement benchmark for Blob Storage.""" On 2015/05/22 at 18:33:18, eakuefner wrote: > nit: newline after Done. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:9: On 2015/05/22 at 18:33:18, eakuefner wrote: > nit: two newlines between top-level definitions. Done. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:17: """ On 2015/05/22 at 18:33:18, eakuefner wrote: > nit: extra newline after docstring. also, can you please make this docstring google-style? https://google-styleguide.googlecode.com/svn/trunk/pyguide.html?showone=Comme... Done. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:18: WRITE_INTERACTION_LABEL = 'Action_CreateBlob' On 2015/05/22 at 18:33:18, eakuefner wrote: > Please move these constants above, out of the class. Done, and made the predicates class methods https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:36: browser_process = \ On 2015/05/22 at 18:33:19, eakuefner wrote: > nit: backslash 1. should not be necessary here since python allows whitespace inside of (),[],{} and 2. is against styleguide. Done. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:42: event_predicate=self._WriteEventPredicate): On 2015/05/22 at 18:33:19, eakuefner wrote: > I don't think this is going to work: event_predicate is supposed to take an event and return a bool, but your predicates are instance methods. I think inlining them would be best, and you can use newlines if it won't fit onto one line. eg: > > event_predicate=(lambda e: e.name == WRITE_INTERACTION_LABEL) (pursuant to moving the events out of the class as i mentioned above) I changed them to class methods, does that work better? I reuse them in two spots so I was thinking it's better to have a method. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:90: for event in [e for e in events \ On 2015/05/22 at 18:33:19, eakuefner wrote: > no backslash here either Done. https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py (right): https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py:20: blob_timeline.BlobTimelineMetric()._AddWriteResultsInternal( On 2015/05/22 at 18:33:19, eakuefner wrote: > I think it would be best to test the public behavior if you can here. As a last resort add a # pylint: disable=protected-access. I'm thinking it's cleaner to just call the internal methods with our event arrays instead of mocking: * model.GetAllProcesses() * having one with p.name == 'Browser' * p.parent.IterAllEvents * renderer_thread.parent.IterAllEvents WDYT? https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py:24: return dict((value.name, value.values) for value in On 2015/05/22 at 18:33:19, eakuefner wrote: > Please call results.DidRunPage above this line. Done.
Whoops, I forgot to upload. Also, I changed to the lambda for the event checking.
dmurph@chromium.org changed reviewers: + kinuko@chromium.org
+kinuko for storage/browser/blob/blob_url_request_job.cc (and fixed tests)
On 2015/05/22 23:02:32, dmurph wrote: > +kinuko for storage/browser/blob/blob_url_request_job.cc lgtm for blob_url_request_job.cc > (and fixed tests)
Gentle ping for ned and ethan :)
https://codereview.chromium.org/1104053006/diff/220001/tools/perf/benchmarks/... File tools/perf/benchmarks/blob_storage.py (right): https://codereview.chromium.org/1104053006/diff/220001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:34: return (value.name.startswith('Action_CreateBlob') or I thought we want to filter on "blob_writes", "blob_write_reads" & "blob_reads" ? https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:56: write_then_reads.append(interaction.end - interaction.start) This is the wrong way of using timeline interaction record. The idea of timeline interaction record is to specify a time range in which we want to compute metrics on. "Why compute metric on a specific time range instead of the whole browsing section's life time?", you may ask. This is mainly to reduce noise. From our experience, we observe many situation in which some metrics X is unstable during a specific time period of the browser, i.e: smoothness metrics are noisy because of some time gap when users intentionally pause, thread time metrics are noisy because of the idle time waiting for the page to load, etc. Hence, there is no semantic built-in in interaction to guarantee it always contain these "write_then_read" actions. https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:63: writes.append(duration) You can use e.thread_duration to make sure that your metric is not sensitive to the OS activities. Caveat is that thread_time info is not available on win, so you need s.t like an if statement to fallback to use walltime for duration on win platform. https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:92: min_read_start = min(event.start, min_read_start) why can we just use reads.append(e.thread_duration)?
lgtm https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py (right): https://codereview.chromium.org/1104053006/diff/180001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline_unittest.py:20: blob_timeline.BlobTimelineMetric()._AddWriteResultsInternal( On 2015/05/22 19:06:21, dmurph wrote: > On 2015/05/22 at 18:33:19, eakuefner wrote: > > I think it would be best to test the public behavior if you can here. As a > last resort add a # pylint: disable=protected-access. > > I'm thinking it's cleaner to just call the internal methods with our event > arrays instead of mocking: > * model.GetAllProcesses() > * having one with p.name == 'Browser' > * p.parent.IterAllEvents > * renderer_thread.parent.IterAllEvents > > WDYT? Fair enough. https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:44: event_predicate=(lambda e: e.name == READ_EVENT_NAME)): this looks fine, but let it be known that _if_ you want to factor this out, @staticmethod will work, but @classmethod won't, because staticmethod creates a true one-argument function whereas classmethod takes the class as an implicit first parameter (this distinction exists in python but not c++ because classes are objects in python). whatever you choose to do from here is fine with me.
sorry, i meant lgtm as long as ned is happy :)
Switched to using thread_duration, using an accumulation of read times for blob read, and fixed the test. https://codereview.chromium.org/1104053006/diff/220001/tools/perf/benchmarks/... File tools/perf/benchmarks/blob_storage.py (right): https://codereview.chromium.org/1104053006/diff/220001/tools/perf/benchmarks/... tools/perf/benchmarks/blob_storage.py:34: return (value.name.startswith('Action_CreateBlob') or On 2015/05/28 at 05:10:12, nednguyen wrote: > I thought we want to filter on "blob_writes", "blob_write_reads" & "blob_reads" ? The name contains the interaction and the result name. Switched to checking for the result name. https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:44: event_predicate=(lambda e: e.name == READ_EVENT_NAME)): On 2015/05/28 at 20:36:56, eakuefner wrote: > this looks fine, but let it be known that _if_ you want to factor this out, @staticmethod will work, but @classmethod won't, because staticmethod creates a true one-argument function whereas classmethod takes the class as an implicit first parameter (this distinction exists in python but not c++ because classes are objects in python). > > whatever you choose to do from here is fine with me. Switched to static methods https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:56: write_then_reads.append(interaction.end - interaction.start) On 2015/05/28 at 05:10:12, nednguyen wrote: > This is the wrong way of using timeline interaction record. > > The idea of timeline interaction record is to specify a time range in which we want to compute metrics on. > > "Why compute metric on a specific time range instead of the whole browsing section's life time?", you may ask. This is mainly to reduce noise. From our experience, we observe many situation in which some metrics X is unstable during a specific time period of the browser, i.e: smoothness metrics are noisy because of some time gap when users intentionally pause, thread time metrics are noisy because of the idle time waiting for the page to load, etc. > > Hence, there is no semantic built-in in interaction to guarantee it always contain these "write_then_read" actions. Based on external discussion, switched to using the read stats https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:63: writes.append(duration) On 2015/05/28 at 05:10:12, nednguyen wrote: > You can use e.thread_duration to make sure that your metric is not sensitive to the OS activities. Caveat is that thread_time info is not available on win, so you need s.t like an if statement to fallback to use walltime for duration on win platform. Done. https://codereview.chromium.org/1104053006/diff/220001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:92: min_read_start = min(event.start, min_read_start) On 2015/05/28 at 05:10:12, nednguyen wrote: > why can we just use reads.append(e.thread_duration)? Done.
https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:103: not self.IsWriteReadInteraction(interaction)): Again, you cannot make any assumption about what interaction labels could be. I think this is partly our fault that this AddResults(self, model, renderer_thread, interactions, results) API give you the full interactions instead of just the time range ~_~ I file a bug about that here: https://code.google.com/p/chromium/issues/detail?id=493785
But this is how I'm computing my metrics. How will I know if my 'read' events were for the write_then_read interaction or the mass reads? OR is there supposed to be just one interaction per AddResults? That would make much more sense w/ the output. On Fri, May 29, 2015 at 10:57 AM <nednguyen@google.com> wrote: > > > https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py > (right): > > > https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:103 > <https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme...>: > not > self.IsWriteReadInteraction(interaction)): > Again, you cannot make any assumption about what interaction labels > could be. > > I think this is partly our fault that this AddResults(self, model, > renderer_thread, interactions, results) API give you the full > interactions instead of just the time range ~_~ > > I file a bug about that here: > https://code.google.com/p/chromium/issues/detail?id=493785 > > https://codereview.chromium.org/1104053006/ > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
On 2015/05/29 at 18:44:54, dmurph wrote: > But this is how I'm computing my metrics. How will I know if my 'read' > events were for the write_then_read interaction or the mass reads? > > OR is there supposed to be just one interaction per AddResults? That would > make much more sense w/ the output. > > On Fri, May 29, 2015 at 10:57 AM <nednguyen@google.com> wrote: > > > > > > > https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... > > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py > > (right): > > > > > > https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:103 > > <https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme...>: > > not > > self.IsWriteReadInteraction(interaction)): > > Again, you cannot make any assumption about what interaction labels > > could be. > > > > I think this is partly our fault that this AddResults(self, model, > > renderer_thread, interactions, results) API give you the full > > interactions instead of just the time range ~_~ > > > > I file a bug about that here: > > https://code.google.com/p/chromium/issues/detail?id=493785 > > > > https://codereview.chromium.org/1104053006/ > > > > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org. > Done, attached an example results here: https://code.google.com/p/chromium/issues/detail?id=489799 let me know what you think :)
A bit of caveat: we will move the interaction record out of the metric name, and make each Value looks s.t like: Value: Page: XYZ Interaction: ABC name: BlobRead (<-- right now, this is ABC_BlobRead) value: 123 units: ms See https://code.google.com/p/chromium/issues/detail?id=461101 https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:74: values=writes, Be aware that if the list is empty, this will cause exception. You may want to do a check like: if not writes: results.AddValue(list_of_scalar_values.ListOfScalarValues( page=results.current_page, name='blob-writes', units='ms', values=None, none_value_reason='No blob write events found') https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:91: reads.append(total_thread_time) Why does this reads contains the list of total_thread_time by interaction? If I read this correctly, the list contains [total_thread_time_of_read_in_record_1, total_thread_time_of_read_in_record_2,...] Is this because you expect the record 1 to contain only read events of the first read, record 2 to contain only read events of the 2nd read? If so, then note that we can't make this assumption. I would just make it as straight forward as output a total number of all read events or the list of all read events' latency found in interaction records, then you can create interaction record with different names in your pages. Doing so will make the BlobTimelineMetric.AddResults called multiple times, which allow you to differentiate the values of one interaction from others https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:99: description='List of durations of blob reading.')) This also needs to deal with empty list
On 2015/06/01 at 23:29:27, nednguyen wrote: > A bit of caveat: we will move the interaction record out of the metric name, and make each Value looks s.t like: > > Value: > Page: XYZ > Interaction: ABC > name: BlobRead (<-- right now, this is ABC_BlobRead) > value: 123 > units: ms > > See https://code.google.com/p/chromium/issues/detail?id=461101 > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:74: values=writes, > Be aware that if the list is empty, this will cause exception. You may want to do a check like: > > if not writes: > results.AddValue(list_of_scalar_values.ListOfScalarValues( > page=results.current_page, > name='blob-writes', > units='ms', > values=None, > none_value_reason='No blob write events found') > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:91: reads.append(total_thread_time) > Why does this reads contains the list of total_thread_time by interaction? > > If I read this correctly, the list contains > [total_thread_time_of_read_in_record_1, total_thread_time_of_read_in_record_2,...] > > Is this because you expect the record 1 to contain only read events of the first read, record 2 to contain only read events of the 2nd read? If so, then note that we can't make this assumption. I would just make it as straight forward as output a total number of all read events or the list of all read events' latency found in interaction records, then you can create interaction record with different names in your pages. Doing so will make the BlobTimelineMetric.AddResults called multiple times, which allow you to differentiate the values of one interaction from others > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:99: description='List of durations of blob reading.')) > This also needs to deal with empty list This means it looks like there will be 0 ways for me to report different metrics from the same 'trace' event in one 'metric'. How can I can do this? As discussed before: I have 2 different situations where I'm measuring the read time. * Worst-case stale read, where it's immediately after write. * Warm read, where it's after write time.
On 2015/06/01 23:42:48, dmurph wrote: > On 2015/06/01 at 23:29:27, nednguyen wrote: > > A bit of caveat: we will move the interaction record out of the metric name, > and make each Value looks s.t like: > > > > Value: > > Page: XYZ > > Interaction: ABC > > name: BlobRead (<-- right now, this is ABC_BlobRead) > > value: 123 > > units: ms > > > > See https://code.google.com/p/chromium/issues/detail?id=461101 > > > > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > > > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:74: values=writes, > > Be aware that if the list is empty, this will cause exception. You may want to > do a check like: > > > > if not writes: > > results.AddValue(list_of_scalar_values.ListOfScalarValues( > > page=results.current_page, > > name='blob-writes', > > units='ms', > > values=None, > > none_value_reason='No blob write events found') > > > > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:91: > reads.append(total_thread_time) > > Why does this reads contains the list of total_thread_time by interaction? > > > > If I read this correctly, the list contains > > [total_thread_time_of_read_in_record_1, > total_thread_time_of_read_in_record_2,...] > > > > Is this because you expect the record 1 to contain only read events of the > first read, record 2 to contain only read events of the 2nd read? If so, then > note that we can't make this assumption. I would just make it as straight > forward as output a total number of all read events or the list of all read > events' latency found in interaction records, then you can create interaction > record with different names in your pages. Doing so will make the > BlobTimelineMetric.AddResults called multiple times, which allow you to > differentiate the values of one interaction from others > > > > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:99: > description='List of durations of blob reading.')) > > This also needs to deal with empty list > > This means it looks like there will be 0 ways for me to report different metrics > from the same 'trace' event in one 'metric'. How can I can do this? As > discussed before: > > I have 2 different situations where I'm measuring the read time. > * Worst-case stale read, where it's immediately after write. > * Warm read, where it's after write time. Wait, I think Ned's caveat has generated a bit of confusion. To be clear, those situations are contained within disjoint interaction records, right?
Switched to UUID-based tracking for reading and expanded tests a bit. patch selfie: http://i.imgur.com/YiEGExB.gif https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:103: not self.IsWriteReadInteraction(interaction)): On 2015/05/29 at 17:57:52, nednguyen wrote: > Again, you cannot make any assumption about what interaction labels could be. > > I think this is partly our fault that this AddResults(self, model, renderer_thread, interactions, results) API give you the full interactions instead of just the time range ~_~ > > I file a bug about that here: https://code.google.com/p/chromium/issues/detail?id=493785 Done. https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:74: values=writes, On 2015/06/01 at 23:29:27, nednguyen wrote: > Be aware that if the list is empty, this will cause exception. You may want to do a check like: > > if not writes: > results.AddValue(list_of_scalar_values.ListOfScalarValues( > page=results.current_page, > name='blob-writes', > units='ms', > values=None, > none_value_reason='No blob write events found') See the line above it :) https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:91: reads.append(total_thread_time) On 2015/06/01 at 23:29:27, nednguyen wrote: > Why does this reads contains the list of total_thread_time by interaction? > > If I read this correctly, the list contains > [total_thread_time_of_read_in_record_1, total_thread_time_of_read_in_record_2,...] > > Is this because you expect the record 1 to contain only read events of the first read, record 2 to contain only read events of the 2nd read? If so, then note that we can't make this assumption. I would just make it as straight forward as output a total number of all read events or the list of all read events' latency found in interaction records, then you can create interaction record with different names in your pages. Doing so will make the BlobTimelineMetric.AddResults called multiple times, which allow you to differentiate the values of one interaction from others Switched to using UUIDs :) https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:99: description='List of durations of blob reading.')) On 2015/06/01 at 23:29:27, nednguyen wrote: > This also needs to deal with empty list See the line above it :)
On 2015/06/02 at 20:04:07, dmurph wrote: > Switched to UUID-based tracking for reading and expanded tests a bit. > > patch selfie: > http://i.imgur.com/YiEGExB.gif I suspect most people still don't know about this amazing feature :D > > https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > https://codereview.chromium.org/1104053006/diff/240001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:103: not self.IsWriteReadInteraction(interaction)): > On 2015/05/29 at 17:57:52, nednguyen wrote: > > Again, you cannot make any assumption about what interaction labels could be. > > > > I think this is partly our fault that this AddResults(self, model, renderer_thread, interactions, results) API give you the full interactions instead of just the time range ~_~ > > > > I file a bug about that here: https://code.google.com/p/chromium/issues/detail?id=493785 > > Done. > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:74: values=writes, > On 2015/06/01 at 23:29:27, nednguyen wrote: > > Be aware that if the list is empty, this will cause exception. You may want to do a check like: > > > > if not writes: > > results.AddValue(list_of_scalar_values.ListOfScalarValues( > > page=results.current_page, > > name='blob-writes', > > units='ms', > > values=None, > > none_value_reason='No blob write events found') > > See the line above it :) > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:91: reads.append(total_thread_time) > On 2015/06/01 at 23:29:27, nednguyen wrote: > > Why does this reads contains the list of total_thread_time by interaction? > > > > If I read this correctly, the list contains > > [total_thread_time_of_read_in_record_1, total_thread_time_of_read_in_record_2,...] > > > > Is this because you expect the record 1 to contain only read events of the first read, record 2 to contain only read events of the 2nd read? If so, then note that we can't make this assumption. I would just make it as straight forward as output a total number of all read events or the list of all read events' latency found in interaction records, then you can create interaction record with different names in your pages. Doing so will make the BlobTimelineMetric.AddResults called multiple times, which allow you to differentiate the values of one interaction from others > > Switched to using UUIDs :) > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:99: description='List of durations of blob reading.')) > On 2015/06/01 at 23:29:27, nednguyen wrote: > > This also needs to deal with empty list > > See the line above it :)
lgtm with nits https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:74: values=writes, On 2015/06/02 20:04:07, dmurph wrote: > On 2015/06/01 at 23:29:27, nednguyen wrote: > > Be aware that if the list is empty, this will cause exception. You may want to > do a check like: > > > > if not writes: > > results.AddValue(list_of_scalar_values.ListOfScalarValues( > > page=results.current_page, > > name='blob-writes', > > units='ms', > > values=None, > > none_value_reason='No blob write events found') > > See the line above it :) Can you add none value with none value reason in the else block? It makes it easier to figure out what happened when the values disappear. https://codereview.chromium.org/1104053006/diff/280001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/280001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:84: uuid = event.args['uuid'] Can you add some comment explain here why we group this by the uuid?
On 2015/06/02 at 21:06:58, nednguyen wrote: > lgtm with nits > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > https://codereview.chromium.org/1104053006/diff/260001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:74: values=writes, > On 2015/06/02 20:04:07, dmurph wrote: > > On 2015/06/01 at 23:29:27, nednguyen wrote: > > > Be aware that if the list is empty, this will cause exception. You may want to > > do a check like: > > > > > > if not writes: > > > results.AddValue(list_of_scalar_values.ListOfScalarValues( > > > page=results.current_page, > > > name='blob-writes', > > > units='ms', > > > values=None, > > > none_value_reason='No blob write events found') > > > > See the line above it :) > > Can you add none value with none value reason in the else block? It makes it easier to figure out what happened when the values disappear. Ah. Yeah I can do that. Just FYI, this means this metric will always show up for all timeline benchmarks.
Actually, it would be worse than that. Every interaction in a benchmark would have two blob metrics. So in my benchmark, my read interaction has a blob-writes metric that's always NaN now. Are you sure this is what you want? To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
Based on outside conversation, added None state and then filter it out in our benchmark. https://codereview.chromium.org/1104053006/diff/280001/tools/telemetry/teleme... File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): https://codereview.chromium.org/1104053006/diff/280001/tools/telemetry/teleme... tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:84: uuid = event.args['uuid'] On 2015/06/02 at 21:06:58, nednguyen wrote: > Can you add some comment explain here why we group this by the uuid? Done.
On 2015/06/02 22:55:45, dmurph wrote: > Based on outside conversation, added None state and then filter it out in our > benchmark. > > https://codereview.chromium.org/1104053006/diff/280001/tools/telemetry/teleme... > File tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py (right): > > https://codereview.chromium.org/1104053006/diff/280001/tools/telemetry/teleme... > tools/telemetry/telemetry/web_perf/metrics/blob_timeline.py:84: uuid = > event.args['uuid'] > On 2015/06/02 at 21:06:58, nednguyen wrote: > > Can you add some comment explain here why we group this by the uuid? > > Done. lgtm again
The CQ bit was checked by dmurph@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from eakuefner@chromium.org, kinuko@chromium.org Link to the patchset: https://codereview.chromium.org/1104053006/#ps300001 (title: "None case, filter nones")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1104053006/300001
The CQ bit was unchecked by commit-bot@chromium.org
Try jobs failed on following builders: chromium_presubmit on tryserver.chromium.linux (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.linux/builders/chromium_presub...)
The CQ bit was checked by dmurph@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from eakuefner@chromium.org, kinuko@chromium.org, nednguyen@google.com Link to the patchset: https://codereview.chromium.org/1104053006/#ps320001 (title: "copyright fix")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1104053006/320001
Message was sent while issue was closed.
Committed patchset #17 (id:320001)
Message was sent while issue was closed.
Patchset 17 (id:??) landed as https://crrev.com/dbd2315e79df68af221c06dadbc00adfcdef07df Cr-Commit-Position: refs/heads/master@{#332541} |