1. 09 Aug, 2021 1 commit
    • Camillo Bruni's avatar
      Reland "[counters] Fix reentrant timers for V8.Execute" · f688fe08
      Camillo Bruni authored
      This is a reland of fffcbaea
      
      Additional fixes:
      - Relax IsStarted DCHECKs in ElapsedTimer for paused_elapsed
      - Add LogEventStatus enum in the API for better testing
      - Rename Logger::StartEnd enum values to kXXX
      - Add additional NestedTimedHistogramScope tests
      
      Original change's description:
      > [counters] Fix reentrant timers for V8.Execute
      >
      > This CL fixes a long standing issue where reentering TimedHistograms
      > scopes would cause spurious measurements. Only the non-nested scopes
      > yielded correct results.
      >
      > Due to the changed numbers, the V8.Execute histogram is renamed to
      > V8.ExecuteMicroSeconds. Note that this histogram is also guarded
      > behind the --slow-histograms flag due to the additional overhead.
      >
      > Unlike before, it does no longer include time for external callbacks
      > and only measures self time. The following example illustrates the
      > new behaviour:
      >
      > 1. Enter V8:           |--+.......+--| self-time: 4 units (reported)
      > 2. Exit V8 (callback):    |-+...+-|    self-time: 2 units (ignored)
      > 3. Re-enter V8:             |---|      self-time: 3 units (reported)
      >
      > This would result in 2 histogram entries with 4 time units for the first
      > V8 slice and 3 units for the nested part. Note that the callback time
      > itself is ignored.
      >
      > This CL attempts to clean up how TimedHistograms work:
      > - Histogram: the base class
      > - TimedHistograms: used for time-related histograms that are not nested
      > - NestedTimeHistograms: Extends TimedHistograms and is used for nested
      >   histograms
      >
      > This CL changes Histograms to not measure time themselves. Measurements
      > happen in the *HistogramScopes:
      > - BaseTimedHistogramScope: Base functionality
      > - TimedHistogramScope: For non-nested measurements
      > - NestedTimedHistogramScope: For nested measurements
      > - PauseNestedTimedHistogramScope: Ignore time during a given scope.
      >   This is used to pause timers during callbacks.
      >
      > Additional changes:
      > - ExternalCallbackScope now contains a PauseNestedTimedHistogramScope
      >   and always sets VMState<EXTERNAL>
      >
      > Bug: v8:11946
      > Change-Id: I45e4b7ff77b5948b605dd50539044cb26222fa21
      > Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3001345
      > Reviewed-by: Omer Katz <omerkatz@chromium.org>
      > Reviewed-by: Thibaud Michaud <thibaudm@chromium.org>
      > Reviewed-by: Victor Gomes <victorgomes@chromium.org>
      > Reviewed-by: Leszek Swirski <leszeks@chromium.org>
      > Commit-Queue: Camillo Bruni <cbruni@chromium.org>
      > Cr-Commit-Position: refs/heads/master@{#76111}
      
      Bug: v8:11946
      Change-Id: Ic2eef7456fbc245febcf780b23418f6ab0bebdb7
      Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3080566
      Commit-Queue: Camillo Bruni <cbruni@chromium.org>
      Reviewed-by: 's avatarLeszek Swirski <leszeks@chromium.org>
      Reviewed-by: 's avatarVictor Gomes <victorgomes@chromium.org>
      Reviewed-by: 's avatarThibaud Michaud <thibaudm@chromium.org>
      Reviewed-by: 's avatarOmer Katz <omerkatz@chromium.org>
      Cr-Commit-Position: refs/heads/master@{#76180}
      f688fe08
  2. 06 Aug, 2021 1 commit
    • Leszek Swirski's avatar
      Revert "[counters] Fix reentrant timers for V8.Execute" · a12c6fa2
      Leszek Swirski authored
      This reverts commit fffcbaea.
      
      Reason for revert: Breaks in Chromium (e.g. https://ci.chromium.org/p/v8/builders/ci/Linux%20V8%20FYI%20Release%20%28NVIDIA%29)
      
      Original change's description:
      > [counters] Fix reentrant timers for V8.Execute
      >
      > This CL fixes a long standing issue where reentering TimedHistograms
      > scopes would cause spurious measurements. Only the non-nested scopes
      > yielded correct results.
      >
      > Due to the changed numbers, the V8.Execute histogram is renamed to
      > V8.ExecuteMicroSeconds. Note that this histogram is also guarded
      > behind the --slow-histograms flag due to the additional overhead.
      >
      > Unlike before, it does no longer include time for external callbacks
      > and only measures self time. The following example illustrates the
      > new behaviour:
      >
      > 1. Enter V8:           |--+.......+--| self-time: 4 units (reported)
      > 2. Exit V8 (callback):    |-+...+-|    self-time: 2 units (ignored)
      > 3. Re-enter V8:             |---|      self-time: 3 units (reported)
      >
      > This would result in 2 histogram entries with 4 time units for the first
      > V8 slice and 3 units for the nested part. Note that the callback time
      > itself is ignored.
      >
      > This CL attempts to clean up how TimedHistograms work:
      > - Histogram: the base class
      > - TimedHistograms: used for time-related histograms that are not nested
      > - NestedTimeHistograms: Extends TimedHistograms and is used for nested
      >   histograms
      >
      > This CL changes Histograms to not measure time themselves. Measurements
      > happen in the *HistogramScopes:
      > - BaseTimedHistogramScope: Base functionality
      > - TimedHistogramScope: For non-nested measurements
      > - NestedTimedHistogramScope: For nested measurements
      > - PauseNestedTimedHistogramScope: Ignore time during a given scope.
      >   This is used to pause timers during callbacks.
      >
      > Additional changes:
      > - ExternalCallbackScope now contains a PauseNestedTimedHistogramScope
      >   and always sets VMState<EXTERNAL>
      >
      > Bug: v8:11946
      > Change-Id: I45e4b7ff77b5948b605dd50539044cb26222fa21
      > Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3001345
      > Reviewed-by: Omer Katz <omerkatz@chromium.org>
      > Reviewed-by: Thibaud Michaud <thibaudm@chromium.org>
      > Reviewed-by: Victor Gomes <victorgomes@chromium.org>
      > Reviewed-by: Leszek Swirski <leszeks@chromium.org>
      > Commit-Queue: Camillo Bruni <cbruni@chromium.org>
      > Cr-Commit-Position: refs/heads/master@{#76111}
      
      Bug: v8:11946
      Change-Id: I954de1afbabf101fb5d4f52eca0d3b80a723385b
      Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3077153
      Bot-Commit: Rubber Stamper <rubber-stamper@appspot.gserviceaccount.com>
      Commit-Queue: Leszek Swirski <leszeks@chromium.org>
      Owners-Override: Leszek Swirski <leszeks@chromium.org>
      Cr-Commit-Position: refs/heads/master@{#76138}
      a12c6fa2
  3. 05 Aug, 2021 1 commit
    • Camillo Bruni's avatar
      [counters] Fix reentrant timers for V8.Execute · fffcbaea
      Camillo Bruni authored
      This CL fixes a long standing issue where reentering TimedHistograms
      scopes would cause spurious measurements. Only the non-nested scopes
      yielded correct results.
      
      Due to the changed numbers, the V8.Execute histogram is renamed to
      V8.ExecuteMicroSeconds. Note that this histogram is also guarded
      behind the --slow-histograms flag due to the additional overhead.
      
      Unlike before, it does no longer include time for external callbacks
      and only measures self time. The following example illustrates the
      new behaviour:
      
      1. Enter V8:           |--+.......+--| self-time: 4 units (reported)
      2. Exit V8 (callback):    |-+...+-|    self-time: 2 units (ignored)
      3. Re-enter V8:             |---|      self-time: 3 units (reported)
      
      This would result in 2 histogram entries with 4 time units for the first
      V8 slice and 3 units for the nested part. Note that the callback time
      itself is ignored.
      
      This CL attempts to clean up how TimedHistograms work:
      - Histogram: the base class
      - TimedHistograms: used for time-related histograms that are not nested
      - NestedTimeHistograms: Extends TimedHistograms and is used for nested
        histograms
      
      This CL changes Histograms to not measure time themselves. Measurements
      happen in the *HistogramScopes:
      - BaseTimedHistogramScope: Base functionality
      - TimedHistogramScope: For non-nested measurements
      - NestedTimedHistogramScope: For nested measurements
      - PauseNestedTimedHistogramScope: Ignore time during a given scope.
        This is used to pause timers during callbacks.
      
      Additional changes:
      - ExternalCallbackScope now contains a PauseNestedTimedHistogramScope
        and always sets VMState<EXTERNAL>
      
      Bug: v8:11946
      Change-Id: I45e4b7ff77b5948b605dd50539044cb26222fa21
      Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3001345Reviewed-by: 's avatarOmer Katz <omerkatz@chromium.org>
      Reviewed-by: 's avatarThibaud Michaud <thibaudm@chromium.org>
      Reviewed-by: 's avatarVictor Gomes <victorgomes@chromium.org>
      Reviewed-by: 's avatarLeszek Swirski <leszeks@chromium.org>
      Commit-Queue: Camillo Bruni <cbruni@chromium.org>
      Cr-Commit-Position: refs/heads/master@{#76111}
      fffcbaea
  4. 18 Oct, 2017 1 commit
  5. 21 Nov, 2016 2 commits
    • cbruni's avatar
      Revert of [counters] RuntimeStats: fix wrong bookkeeping when dynamically... · 10a31136
      cbruni authored
      Revert of [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters. (patchset #10 id:180001 of https://codereview.chromium.org/2511093002/ )
      
      Reason for revert:
      Wronged it even more.
      
      Original issue's 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/f6c74d964d9387df4bed3d8c1ded51eb9e8aa6e8
      > Cr-Commit-Position: refs/heads/master@{#41142}
      
      TBR=ishell@chromium.org
      # Skipping CQ checks because original CL landed less than 1 days ago.
      NOPRESUBMIT=true
      NOTREECHECKS=true
      NOTRY=true
      BUG=
      
      Review-Url: https://codereview.chromium.org/2519073002
      Cr-Commit-Position: refs/heads/master@{#41150}
      10a31136
    • cbruni's avatar
      [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters · f6c74d96
      cbruni authored
      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=
      
      Review-Url: https://codereview.chromium.org/2511093002
      Cr-Commit-Position: refs/heads/master@{#41142}
      f6c74d96
  6. 30 Sep, 2015 1 commit
  7. 20 Apr, 2015 1 commit
  8. 02 Sep, 2014 1 commit
  9. 04 Aug, 2014 1 commit
  10. 30 Jun, 2014 1 commit
  11. 03 Jun, 2014 1 commit
  12. 29 Apr, 2014 1 commit
  13. 04 Oct, 2013 1 commit
  14. 02 Oct, 2013 1 commit
  15. 12 Sep, 2013 1 commit
  16. 11 Sep, 2013 2 commits
  17. 10 Sep, 2013 1 commit
  18. 09 Sep, 2013 1 commit
  19. 29 Aug, 2013 1 commit
  20. 28 Aug, 2013 2 commits