Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
2511093002:
[counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters. (Closed)
|
Created:
4 years, 1 month ago by Camillo Bruni Modified:
4 years ago CC:
fmeawad, v8-reviews_googlegroups.com Target Ref:
refs/pending/heads/master Project:
v8 Visibility:
Public. |
Description[counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters
RuntimeTimerScopes always subtract their own time from the parent timer's
counter to properly account for the own time. Once a scope is destructed it
adds it own timer to the current active counter. However, if the current
counter is changed with CorrectCurrentCounterId we will attribute all the
subtimers to the previous counter, and add the own time to the new counter.
This way it is possible to end up with negative times in certain counters but
the overall would still be correct.
BUG=
Committed: https://crrev.com/244dd002c50dca663cb41686917e2006149e29e8
Cr-Commit-Position: refs/heads/master@{#41254}
Patch Set 1 #
Total comments: 4
Patch Set 2 : formatting #
Total comments: 8
Patch Set 3 : partly addressing nits and implementing unittests #Patch Set 4 : fix windows #Patch Set 5 : moar tests #
Total comments: 20
Patch Set 6 : addressing comments #Patch Set 7 : adding more comments #Patch Set 8 : more comments #
Total comments: 3
Patch Set 9 : fixing compilation #Patch Set 10 : trying to fix win #Patch Set 11 : rebasing for real #Patch Set 12 : using the stopwatch principle to pause the outer timer #Patch Set 13 : adding subtime_ field on RuntimeCallTimer #
Total comments: 3
Patch Set 14 : succumbing to igors will :D #Patch Set 15 : reverting elapsed-timer.h #Patch Set 16 : increase test epsilon to 20ms #Patch Set 17 : merge with master #
Total comments: 1
Messages
Total messages: 91 (60 generated)
cbruni@chromium.org changed reviewers: + ishell@chromium.org
PTAL https://codereview.chromium.org/2511093002/diff/1/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/1/src/counters-inl.h#newcode31 src/counters-inl.h:31: parent()->Subtract(delta); newly added Subtract https://codereview.chromium.org/2511093002/diff/1/src/counters.h File src/counters.h (left): https://codereview.chromium.org/2511093002/diff/1/src/counters.h#oldcode539 src/counters.h:539: } moved all functions to counters-inl.h https://codereview.chromium.org/2511093002/diff/1/src/counters.h#oldcode1334 src/counters.h:1334: }; Just moved this whole block to put all runtime stuff in one place.
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
Description was changed from ========== g br -m # Enter a description of the change. [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overal would still be correct. BUG= ========== to ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overal would still be correct. BUG= ==========
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: This issue passed the CQ dry run.
Description was changed from ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overal would still be correct. BUG= ========== to ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= ==========
https://codereview.chromium.org/2511093002/diff/1/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/1/src/counters-inl.h#newcode38 src/counters-inl.h:38: // from the current counter. This way we can easily the counter of an active .. can easily [change?] the counter of ... https://codereview.chromium.org/2511093002/diff/20001/src/base/platform/elaps... File src/base/platform/elapsed-timer.h (right): https://codereview.chromium.org/2511093002/diff/20001/src/base/platform/elaps... src/base/platform/elapsed-timer.h:79: start_ticks_ -= delta; Maybe call it Subtract(delta) expecting non-negative values to make it more clear and say that we are subtracting delta by adding to the start_ticks. Otherwise there are too many negations involved :) https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h#newc... src/counters-inl.h:13: inline void RuntimeCallTimer::Start(RuntimeCallCounter* counter, Remove inline here and below. https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h#newc... src/counters-inl.h:45: base::TimeDelta delta = timer_.Elapsed(); Maybe it's better to just call a Restart() here instead of calling Elapsed() here and Restart() at the end - this way we will not drop a piece of the time on the floor. Maybe what we need instead of Elapsed() is a Snapshot() function: public: void RuntimeCallTimer::Snapshot() { Snapshot(ElapsedTimer::Now()); } private: void RuntimeCallTimer::Snapshot(TimeTicks now) { base::TimeDelta delta = timer_.Restart(now); // add this one counter_->time += delta; if (parent()) { parent()->Subtract(delta); parent()->Snapshot(now); } } https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h#newc... src/counters-inl.h:48: parent()->counter_->time -= delta; Anyway parent()->Subtract(delta); to avoid multiple corrections.
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: v8_win64_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win64_rel_ng/builds/18022)
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
PTAL again https://codereview.chromium.org/2511093002/diff/20001/src/base/platform/elaps... File src/base/platform/elapsed-timer.h (right): https://codereview.chromium.org/2511093002/diff/20001/src/base/platform/elaps... src/base/platform/elapsed-timer.h:79: start_ticks_ -= delta; On 2016/11/18 at 09:55:45, Igor Sheludko wrote: > Maybe call it Subtract(delta) expecting non-negative values to make it more clear and say that we are subtracting delta by adding to the start_ticks. Otherwise there are too many negations involved :) What's not wrong with double double negation negations?? done. https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h#newc... src/counters-inl.h:13: inline void RuntimeCallTimer::Start(RuntimeCallCounter* counter, On 2016/11/18 at 09:55:45, Igor Sheludko wrote: > Remove inline here and below. done. https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h#newc... src/counters-inl.h:45: base::TimeDelta delta = timer_.Elapsed(); On 2016/11/18 at 09:55:45, Igor Sheludko wrote: > Maybe it's better to just call a Restart() here instead of calling Elapsed() here and Restart() at the end - this way we will not drop a piece of the time on the floor. > > > Maybe what we need instead of Elapsed() is a Snapshot() function: > public: > void RuntimeCallTimer::Snapshot() { > Snapshot(ElapsedTimer::Now()); > } > > private: > void RuntimeCallTimer::Snapshot(TimeTicks now) { > base::TimeDelta delta = timer_.Restart(now); // add this one > counter_->time += delta; > if (parent()) { > parent()->Subtract(delta); > parent()->Snapshot(now); > } > } good point, implemented this way. https://codereview.chromium.org/2511093002/diff/20001/src/counters-inl.h#newc... src/counters-inl.h:48: parent()->counter_->time -= delta; On 2016/11/18 at 09:55:45, Igor Sheludko wrote: > Anyway > parent()->Subtract(delta); > to avoid multiple corrections. done
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: v8_win_compile_dbg on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_compile_dbg/builds/2...) v8_win_nosnap_shared_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_nosnap_shared_rel_ng...)
Almost there :) https://codereview.chromium.org/2511093002/diff/80001/src/base/platform/elaps... File src/base/platform/elapsed-timer.h (right): https://codereview.chromium.org/2511093002/diff/80001/src/base/platform/elaps... src/base/platform/elapsed-timer.h:57: TimeDelta Restart(TimeTicks ticks) { s/ticks/now/ to be clear. https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h#newc... src/counters-inl.h:38: // from the current counter. This way we can easily the counter of an active .. can easily [change?] the counter of ... https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h#newc... src/counters-inl.h:45: base::TimeTicks now = base::TimeTicks::HighResolutionNow(); I'd prefer to make ElapsedTimer::Now() public to be in sync with its implementation. https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h#newc... src/counters-inl.h:47: base::TimeDelta delta; base::TimeDelta delta = timer_.Restart(now); https://codereview.chromium.org/2511093002/diff/80001/src/counters.h File src/counters.h (right): https://codereview.chromium.org/2511093002/diff/80001/src/counters.h#newcode252 src/counters.h:252: // Returns true if the timer is runnibase::ng. Spurious change. https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... File test/unittests/counters-unittest.cc (right): https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:64: void Sleep(int32_t microseconds) { Probably you don't need microseconds precision. WDYT: void Sleep(int milliseconds) { ElapsedTimer timer; TimeDelta delta = TimeDelta::FromMilliseconds(milliseconds); timer.Start(); while (!timer.HasExpired(delta)) { base::OS::Sleep(0); // or 10? } } Inspired by TEST(TimeTicks, IsMonotonic). https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:68: const uint32_t kTimeMargin = 150; Maybe kEpsilonMs = 50; https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:240: Sleep(500); Probably 100-300 ms should be enough... https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:245: EXPECT_IN_RANGE(500, counter()->time.InMicroseconds(), 500 + kTimeMargin); ... because what we are testing here and below is the RuntimeCallStats machinery but not the underlying counter. https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:258: Maybe Sleep here as well. https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:276: EXPECT_EQ(-counter()->time, counter()->time); We never subtract from time. This should start failing once you fix delta. https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:280: Sleep(500); Maybe you can make the numbers different so that we can check that the time interval went to the right counter. https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:328: } Maybe Sleep between scopes too to ensure that this time is not counted. https://codereview.chromium.org/2511093002/diff/80001/test/unittests/counters... test/unittests/counters-unittest.cc:397: stats()->Print(std::cerr); Test driver does not like a lot of output. You may consider printing to std::ostringstream. You can also try to Sleep/Print several times. It should not affect the resulting time.
https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h#newc... src/counters-inl.h:47: base::TimeDelta delta; On 2016/11/18 18:56:27, Igor Sheludko wrote: > base::TimeDelta delta = timer_.Restart(now); Please ignore this, but... https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h#newc... src/counters-inl.h:51: delta = timer->timer_.Restart(now); ... move this up before Subtract().
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
PTAL again https://codereview.chromium.org/2511093002/diff/80001/src/base/platform/elaps... File src/base/platform/elapsed-timer.h (right): https://codereview.chromium.org/2511093002/diff/80001/src/base/platform/elaps... src/base/platform/elapsed-timer.h:57: TimeDelta Restart(TimeTicks ticks) { On 2016/11/18 at 18:56:27, Igor Sheludko wrote: > s/ticks/now/ to be clear. done. https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h#newc... src/counters-inl.h:38: // from the current counter. This way we can easily the counter of an active On 2016/11/18 at 18:56:27, Igor Sheludko wrote: > .. can easily [change?] the counter of ... done. https://codereview.chromium.org/2511093002/diff/80001/src/counters-inl.h#newc... src/counters-inl.h:45: base::TimeTicks now = base::TimeTicks::HighResolutionNow(); On 2016/11/18 at 18:56:27, Igor Sheludko wrote: > I'd prefer to make ElapsedTimer::Now() public to be in sync with its implementation. done. https://codereview.chromium.org/2511093002/diff/80001/src/counters.h File src/counters.h (right): https://codereview.chromium.org/2511093002/diff/80001/src/counters.h#newcode252 src/counters.h:252: // Returns true if the timer is runnibase::ng. On 2016/11/18 at 18:56:27, Igor Sheludko wrote: > Spurious change. done.
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: v8_linux_gcc_compile_rel on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_linux_gcc_compile_rel/bu...)
lgtm modulo nits: https://codereview.chromium.org/2511093002/diff/140001/src/counters-inl.h File src/counters-inl.h (right): https://codereview.chromium.org/2511093002/diff/140001/src/counters-inl.h#new... src/counters-inl.h:47: base::TimeDelta delta = base::TimeDeltae::FromMicroseconds(0); s/TimeDeltae/TimeDelta/ https://codereview.chromium.org/2511093002/diff/140001/src/counters-inl.h#new... src/counters-inl.h:50: // Iteration 1: subtract 0 from the the current timer (this). s/the the/the/ https://codereview.chromium.org/2511093002/diff/140001/src/counters-inl.h#new... src/counters-inl.h:51: // Iteration n+1: subtract the time (delta) from the subtimer. subtract subtimer's time (delta) from the the current timer.
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: v8_win_nosnap_shared_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_nosnap_shared_rel_ng...)
The CQ bit was checked by cbruni@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from ishell@chromium.org Link to the patchset: https://codereview.chromium.org/2511093002/#ps180001 (title: "trying to fix win")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
CQ is committing da patch.
Bot data: {"patchset_id": 180001, "attempt_start_ts": 1479734282795570,
"parent_rev": ["fec857775b40f999c526008a7157fb304fe9a330", null], "commit_rev":
["e78299684d8d3d3d7134d2cdb096f2e0121d9a01", null]}
Message was sent while issue was closed.
Description was changed from ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= ========== to ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= ==========
Message was sent while issue was closed.
Committed patchset #10 (id:180001)
Message was sent while issue was closed.
Description was changed from ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= ========== to ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= Committed: https://crrev.com/f6c74d964d9387df4bed3d8c1ded51eb9e8aa6e8 Cr-Commit-Position: refs/heads/master@{#41142} ==========
Message was sent while issue was closed.
Patchset 10 (id:??) landed as https://crrev.com/f6c74d964d9387df4bed3d8c1ded51eb9e8aa6e8 Cr-Commit-Position: refs/heads/master@{#41142}
Message was sent while issue was closed.
A revert of this CL (patchset #10 id:180001) has been created in https://codereview.chromium.org/2519073002/ by cbruni@chromium.org. The reason for reverting is: Wronged it even more..
Patchset #11 (id:200001) has been deleted
Patchset #11 (id:220001) has been deleted
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
PTAL again
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: v8_win_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_rel_ng/builds/18313) v8_win_rel_ng_triggered on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_rel_ng_triggered/bui...)
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
PTAL again again :)
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: v8_win_nosnap_shared_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_nosnap_shared_rel_ng...) v8_win_nosnap_shared_rel_ng_triggered on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_nosnap_shared_rel_ng...)
The CQ bit was checked by fmeawad@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: v8_win_nosnap_shared_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_nosnap_shared_rel_ng...) v8_win_nosnap_shared_rel_ng_triggered on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_win_nosnap_shared_rel_ng...)
lpy@chromium.org changed reviewers: + lpy@chromium.org
LGTM, just have one concern. https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc File src/counters.cc (right): https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc#newcod... src/counters.cc:301: delta = timer->Restart(now); I think there's a problem here. In order to maintain accurate time, I think we should always restart timer in the order from parent to child, otherwise parent may end up with negative time, because the timer of child restarts to count before we restart the timer of parent. WDYT?
https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc File src/counters.cc (right): https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc#newcod... src/counters.cc:296: base::TimeDelta delta = base::TimeDelta(); Nit: you can drop = base::TimeDelta(). https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc#newcod... src/counters.cc:301: delta = timer->Restart(now); On 2016/11/22 22:25:44, lpy wrote: > I think there's a problem here. In order to maintain accurate time, I think we > should always restart timer in the order from parent to child, otherwise parent > may end up with negative time, because the timer of child restarts to count > before we restart the timer of parent. > > WDYT? We request "now" value only once and then use it to restart timers. So the order of Restart()s does not matter but it matters for proper subtracting time measured by child from from time measured by parent timer.
On 2016/11/22 22:53:59, Igor Sheludko wrote: > https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc > File src/counters.cc (right): > > https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc#newcod... > src/counters.cc:296: base::TimeDelta delta = base::TimeDelta(); > Nit: you can drop = base::TimeDelta(). > > https://codereview.chromium.org/2511093002/diff/280001/src/counters.cc#newcod... > src/counters.cc:301: delta = timer->Restart(now); > On 2016/11/22 22:25:44, lpy wrote: > > I think there's a problem here. In order to maintain accurate time, I think we > > should always restart timer in the order from parent to child, otherwise > parent > > may end up with negative time, because the timer of child restarts to count > > before we restart the timer of parent. > > > > WDYT? > > We request "now" value only once and then use it to restart timers. So the order > of Restart()s does not matter but it matters for proper subtracting time > measured by child from from time measured by parent timer. right, I think I missed the implementation details in elapsed-timer.h, thanks for pointing it out.
lgtm
The CQ bit was checked by cbruni@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: This issue passed the CQ dry run.
The CQ bit was checked by cbruni@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from ishell@chromium.org, lpy@chromium.org Link to the patchset: https://codereview.chromium.org/2511093002/#ps320001 (title: "reverting elapsed-timer.h")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
CQ is committing da patch.
Bot data: {"patchset_id": 320001, "attempt_start_ts": 1479903669180870,
"parent_rev": "1dbed8a4a5435d2ff9f145a78c8e04b2780b8fd4", "commit_rev":
"d39d7123a00a0585e383572169d540e899578f7d"}
Message was sent while issue was closed.
Committed patchset #15 (id:320001)
Message was sent while issue was closed.
Description was changed from ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= Committed: https://crrev.com/f6c74d964d9387df4bed3d8c1ded51eb9e8aa6e8 Cr-Commit-Position: refs/heads/master@{#41142} ========== to ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= Committed: https://crrev.com/f6c74d964d9387df4bed3d8c1ded51eb9e8aa6e8 Committed: https://crrev.com/491651792d7818aed04eaeffb9890b5a309b543e Cr-Original-Commit-Position: refs/heads/master@{#41142} Cr-Commit-Position: refs/heads/master@{#41214} ==========
Message was sent while issue was closed.
Patchset 15 (id:??) landed as https://crrev.com/491651792d7818aed04eaeffb9890b5a309b543e Cr-Commit-Position: refs/heads/master@{#41214}
Message was sent while issue was closed.
A revert of this CL (patchset #15 id:320001) has been created in https://codereview.chromium.org/2526843002/ by machenbach@chromium.org. The reason for reverting is: The test is very flaky on the bots, e.g.: https://build.chromium.org/p/client.v8/builders/V8%20Linux64%20ASAN/builds/17031 https://build.chromium.org/p/client.v8/builders/V8%20Linux%20-%20shared/build....
The CQ bit was checked by cbruni@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from ishell@chromium.org, lpy@chromium.org Link to the patchset: https://codereview.chromium.org/2511093002/#ps340001 (title: "increase test epsilon to 20ms")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Try jobs failed on following builders: v8_linux64_avx2_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_linux64_avx2_rel_ng/buil...) v8_linux64_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_linux64_rel_ng/builds/16788) v8_linux_gcc_compile_rel on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_linux_gcc_compile_rel/bu...) v8_linux_nodcheck_rel_ng on master.tryserver.v8 (JOB_FAILED, http://build.chromium.org/p/tryserver.v8/builders/v8_linux_nodcheck_rel_ng/bu...)
Description was changed from ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= Committed: https://crrev.com/f6c74d964d9387df4bed3d8c1ded51eb9e8aa6e8 Committed: https://crrev.com/491651792d7818aed04eaeffb9890b5a309b543e Cr-Original-Commit-Position: refs/heads/master@{#41142} Cr-Commit-Position: refs/heads/master@{#41214} ========== to ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= ==========
The CQ bit was checked by cbruni@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from ishell@chromium.org, lpy@chromium.org Link to the patchset: https://codereview.chromium.org/2511093002/#ps360001 (title: "merge with master")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
machenbach@chromium.org changed reviewers: + machenbach@chromium.org
https://codereview.chromium.org/2511093002/diff/360001/test/unittests/counter... File test/unittests/counters-unittest.cc (right): https://codereview.chromium.org/2511093002/diff/360001/test/unittests/counter... test/unittests/counters-unittest.cc:77: const uint32_t kEpsilonMs = 20; Hmm, is that rock solid?
On 2016/11/24 at 09:48:46, machenbach wrote: > https://codereview.chromium.org/2511093002/diff/360001/test/unittests/counter... > File test/unittests/counters-unittest.cc (right): > > https://codereview.chromium.org/2511093002/diff/360001/test/unittests/counter... > test/unittests/counters-unittest.cc:77: const uint32_t kEpsilonMs = 20; > Hmm, is that rock solid? Not much I can do about except increasing it until none of the bots is flaky anymore.
On 2016/11/24 09:59:38, Camillo Bruni wrote: > On 2016/11/24 at 09:48:46, machenbach wrote: > > > https://codereview.chromium.org/2511093002/diff/360001/test/unittests/counter... > > File test/unittests/counters-unittest.cc (right): > > > > > https://codereview.chromium.org/2511093002/diff/360001/test/unittests/counter... > > test/unittests/counters-unittest.cc:77: const uint32_t kEpsilonMs = 20; > > Hmm, is that rock solid? > > Not much I can do about except increasing it until none of the bots is flaky > anymore. ok :(
CQ is committing da patch.
Bot data: {"patchset_id": 360001, "attempt_start_ts": 1479980263774030,
"parent_rev": "47d84e4f355e0a411b07f8fd988d18bb391c3a69", "commit_rev":
"8993b59043e8c19a5eb79e6419e6b90522df631c"}
Message was sent while issue was closed.
Committed patchset #17 (id:360001)
Message was sent while issue was closed.
Description was changed from ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= ========== to ========== [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters RuntimeTimerScopes always subtract their own time from the parent timer's counter to properly account for the own time. Once a scope is destructed it adds it own timer to the current active counter. However, if the current counter is changed with CorrectCurrentCounterId we will attribute all the subtimers to the previous counter, and add the own time to the new counter. This way it is possible to end up with negative times in certain counters but the overall would still be correct. BUG= Committed: https://crrev.com/244dd002c50dca663cb41686917e2006149e29e8 Cr-Commit-Position: refs/heads/master@{#41254} ==========
Message was sent while issue was closed.
Patchset 17 (id:??) landed as https://crrev.com/244dd002c50dca663cb41686917e2006149e29e8 Cr-Commit-Position: refs/heads/master@{#41254}
Message was sent while issue was closed.
This killed build performance, at least on Windows, see https://bugs.chromium.org/p/chromium/issues/detail?id=668748 |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
