Trace viewer creates weird visualization when async trace events are involved |
|||||
Issue descriptionI don't know whether this is an issue with trace viewer or Perfetto, or on which level of the stack the actual problem is. That said, the trace that is visualized differs with and without Perfetto. Please re-assign if I got the area wrong. What happens: - V8 uses sync trace events - Blink starts and ends an async trace event from within sync V8 trace events. In the old world, the trace viewer would just overlap the events, which still keeps nesting in a sane state. In the Perfetto world, the sync event gets extended (?) creating the illusion of a nested event. The async event is also dropped. See the attached example of how things are visualized. (I tested this by disabling Perfetto through tools/perf/core/perf_benchmark.py)
,
Nov 30
mlippautz: Can you confirm this looks normal again?
,
Nov 30
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/6a796b426b1ff987c8e4fd63d838731bcfd50d54 commit 6a796b426b1ff987c8e4fd63d838731bcfd50d54 Author: oysteine <oysteine@chromium.org> Date: Fri Nov 30 20:55:56 2018 Revert "Perfetto: Stop splitting _COMPLETE events" This reverts commit 53e8b2a294d66219b5c4daf00dda1cb9f822a54f. Reason for revert: crbug.com/910704 Original change's description: > Perfetto: Stop splitting _COMPLETE events > > The current Perfetto backend splits _COMPLETE trace events into > separate _BEGIN and _END pairs, as it's not very feasible to modify > existing events after they're written into the Shared Memory Buffers. > > This is causing some issues with the trace-viewer which has some > assumptions about the ordering of begin/end events vs. async events, > and is also bloating the sizes of traces and adding extra > overhead for the perf infra. > > Instead, we now keep the _COMPLETE events in an internal stack in > TLS and only emit them when we have their duration. > > R=eseckler@chromium.org,skyostil@chromium.org > > Bug: 909728, 888558 > Change-Id: I80e37264de66d8bbcb6c9095d21047957fd6eb9f > Reviewed-on: https://chromium-review.googlesource.com/c/1354503 > Commit-Queue: oysteine <oysteine@chromium.org> > Reviewed-by: Eric Seckler <eseckler@chromium.org> > Reviewed-by: Sami Kyöstilä <skyostil@chromium.org> > Cr-Commit-Position: refs/heads/master@{#612360} TBR=oysteine@chromium.org,skyostil@chromium.org,eseckler@chromium.org Change-Id: I0cda9ab36248042c3889d810bfd07a6d03a6d58e No-Presubmit: true No-Tree-Checks: true No-Try: true Bug: 909728, 888558 Reviewed-on: https://chromium-review.googlesource.com/c/1357500 Reviewed-by: oysteine <oysteine@chromium.org> Commit-Queue: oysteine <oysteine@chromium.org> Cr-Commit-Position: refs/heads/master@{#612776} [modify] https://crrev.com/6a796b426b1ff987c8e4fd63d838731bcfd50d54/base/trace_event/trace_log.cc [modify] https://crrev.com/6a796b426b1ff987c8e4fd63d838731bcfd50d54/base/trace_event/trace_log.h [modify] https://crrev.com/6a796b426b1ff987c8e4fd63d838731bcfd50d54/base/trace_event/traced_value.cc [modify] https://crrev.com/6a796b426b1ff987c8e4fd63d838731bcfd50d54/services/tracing/public/cpp/perfetto/trace_event_data_source.cc [modify] https://crrev.com/6a796b426b1ff987c8e4fd63d838731bcfd50d54/services/tracing/public/cpp/perfetto/trace_event_data_source.h [modify] https://crrev.com/6a796b426b1ff987c8e4fd63d838731bcfd50d54/services/tracing/public/cpp/perfetto/trace_event_data_source_unittest.cc
,
Dec 7
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/9d830c214cd1c59958ee19403b446fa5b796e794 commit 9d830c214cd1c59958ee19403b446fa5b796e794 Author: Oystein Eftevaag <oysteine@google.com> Date: Fri Dec 07 01:16:41 2018 Reland "Perfetto: Stop splitting _COMPLETE events" This is a reland of 53e8b2a294d66219b5c4daf00dda1cb9f822a54f Relanding after https://chromium-review.googlesource.com/c/catapult/+/1364251 which is what caused the failures triggering the revert last time. Original change's description: > Perfetto: Stop splitting _COMPLETE events > > The current Perfetto backend splits _COMPLETE trace events into > separate _BEGIN and _END pairs, as it's not very feasible to modify > existing events after they're written into the Shared Memory Buffers. > > This is causing some issues with the trace-viewer which has some > assumptions about the ordering of begin/end events vs. async events, > and is also bloating the sizes of traces and adding extra > overhead for the perf infra. > > Instead, we now keep the _COMPLETE events in an internal stack in > TLS and only emit them when we have their duration. > TBR=eseckler@chromium.org,skyostil@chromium.org > > Bug: 909728, 888558 > Change-Id: I80e37264de66d8bbcb6c9095d21047957fd6eb9f > Reviewed-on: https://chromium-review.googlesource.com/c/1354503 > Commit-Queue: oysteine <oysteine@chromium.org> > Reviewed-by: Eric Seckler <eseckler@chromium.org> > Reviewed-by: Sami Kyöstilä <skyostil@chromium.org> > Cr-Commit-Position: refs/heads/master@{#612360} Bug: 909728, 888558 Change-Id: I5e3d6e0f170066011e2a5b452969d9c8cd18ac4f Reviewed-on: https://chromium-review.googlesource.com/c/1359304 Reviewed-by: oysteine <oysteine@chromium.org> Commit-Queue: oysteine <oysteine@chromium.org> Cr-Commit-Position: refs/heads/master@{#614540} [modify] https://crrev.com/9d830c214cd1c59958ee19403b446fa5b796e794/base/trace_event/trace_log.cc [modify] https://crrev.com/9d830c214cd1c59958ee19403b446fa5b796e794/base/trace_event/trace_log.h [modify] https://crrev.com/9d830c214cd1c59958ee19403b446fa5b796e794/base/trace_event/traced_value.cc [modify] https://crrev.com/9d830c214cd1c59958ee19403b446fa5b796e794/services/tracing/public/cpp/perfetto/trace_event_data_source.cc [modify] https://crrev.com/9d830c214cd1c59958ee19403b446fa5b796e794/services/tracing/public/cpp/perfetto/trace_event_data_source.h [modify] https://crrev.com/9d830c214cd1c59958ee19403b446fa5b796e794/services/tracing/public/cpp/perfetto/trace_event_data_source_unittest.cc |
|||||
►
Sign in to add a comment |
|||||
Comment 1 by bugdroid1@chromium.org
, Nov 29