• yurys@chromium.org's avatar
    Fix test-cpu-profiler/FunctionCallSample flakiness under GC stress testing · 44dfaa2a
    yurys@chromium.org authored
    The test flakes on "V8 GC Stress" bots and the sample looks like this:
    [Top down]:
       90     0   (root) [-1] #0 1
        1     1    (program) [-1] #0 2
       89    89    (garbage collector) [-1] #0 3
    which means that almost all samples are inside GC and we have no |start| node in the collected profile.
    
    Running the test with different combinations of --gc-interval=500 and --stress-compaction flags gives the results quoted below. They don't give a ground to require |start| node presense in the profile when doing GC stress testing. So this change makes the |start| node optional in the collected profile if GC stress testing is on.
    
    $ ./out/ia32.debug/cctest --gc-interval=500 --stress-compaction --trace-gc  test-cpu-profiler/FunctionCallSample
    [10291]       76 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 49.5 ms (+ 0.2 ms in 1 steps since start of marking, biggest step 0.2 ms) [StackGuard GC request] [GC in old space requested].
    [10291]      110 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 25.3 ms [Logger::LogCompiledFunctions] [GC in old space requested].
    [10291]      135 ms: Mark-sweep 0.4 (17.8) -> 0.4 (17.8) MB, 22.8 ms [Logger::LogAccessorCallbacks] [GC in old space requested].
    [10291]      179 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 39.9 ms (+ 0.1 ms in 1 steps since start of marking, biggest step 0.1 ms) [Runtime::PerformGC] [GC in old space forced by flags].
    [10291]      209 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 29.1 ms (+ 0.1 ms in 1 steps since start of marking, biggest step 0.1 ms) [Runtime::PerformGC] [GC in old space forced by flags].
    [10291]      240 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 29.1 ms (+ 0.1 ms in 1 steps since start of marking, biggest step 0.1 ms) [Runtime::PerformGC] [GC in old space forced by flags].
    [Top down]:
       99     0   (root) [-1] #0 1
        4     4    start [-1] #16 3
       93    93    (garbage collector) [-1] #0 4
        2     2    (program) [-1] #0 2
    
    $ ./out/ia32.debug/cctest --gc-interval=500  --trace-gc  test-cpu-profiler/FunctionCallSample
    [10328]       46 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 14.9 ms [Logger::LogCompiledFunctions] [GC in old space requested].
    [10328]       61 ms: Mark-sweep 0.4 (17.8) -> 0.4 (17.8) MB, 12.9 ms [Logger::LogAccessorCallbacks] [GC in old space requested].
    [10328]       65 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.3 ms [Runtime::PerformGC].
    [10328]       67 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.3 ms [Runtime::PerformGC].
    [10328]       69 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       70 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       72 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       73 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       75 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       77 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       78 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       80 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       81 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       83 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       85 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       86 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       88 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       89 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       91 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       93 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       94 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.3 ms [Runtime::PerformGC].
    [10328]       96 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       97 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]       99 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      101 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      102 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      104 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      105 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      107 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      109 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      110 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      112 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      113 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.3 ms [Runtime::PerformGC].
    [10328]      115 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      117 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      118 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      120 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      121 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      123 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      125 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      126 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      128 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      129 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      131 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      133 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      134 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      136 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      137 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      139 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      141 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      142 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      144 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.3 ms [Runtime::PerformGC].
    [10328]      145 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      147 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      149 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      150 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      152 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      153 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.3 ms [Runtime::PerformGC].
    [10328]      155 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      157 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      158 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      160 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      162 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [10328]      163 ms: Scavenge 0.5 (17.8) -> 0.4 (17.8) MB, 1.2 ms [Runtime::PerformGC].
    [Top down]:
       95     0   (root) [-1] #0 1
       12    11    start [-1] #16 3
        1     1      bar [-1] #16 4
       81    81    (garbage collector) [-1] #0 5
        2     2    (program) [-1] #0 2
    
    $ ./out/ia32.debug/cctest --stress-compaction --trace-gc  test-cpu-profiler/FunctionCallSample
    [10355]       76 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 49.9 ms (+ 0.1 ms in 1 steps since start of marking, biggest step 0.1 ms) [StackGuard GC request] [GC in old space requested].
    [10355]      110 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 25.5 ms [Logger::LogCompiledFunctions] [GC in old space requested].
    [10355]      135 ms: Mark-sweep 0.4 (17.8) -> 0.4 (17.8) MB, 22.9 ms [Logger::LogAccessorCallbacks] [GC in old space requested].
    [10355]      189 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 49.8 ms (+ 0.2 ms in 1 steps since start of marking, biggest step 0.2 ms) [StackGuard GC request] [GC in old space requested].
    [10355]      234 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 42.5 ms (+ 0.1 ms in 1 steps since start of marking, biggest step 0.1 ms) [StackGuard GC request] [GC in old space requested].
    [10355]      278 ms: Mark-sweep 0.5 (17.8) -> 0.4 (17.8) MB, 42.5 ms (+ 0.1 ms in 1 steps since start of marking, biggest step 0.1 ms) [StackGuard GC request] [GC in old space requested].
    [Top down]:
      135     0   (root) [-1] #0 1
        6     6    start [-1] #16 3
      127   127    (garbage collector) [-1] #0 4
        2     2    (program) [-1] #0 2
    
    BUG=None
    R=jkummerow@chromium.org, loislo@chromium.org
    
    Review URL: https://codereview.chromium.org/18068012
    
    git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@15471 ce2b1a6d-e550-0410-aec6-3dcde31c8c00
    44dfaa2a
Name
Last commit
Last update
benchmarks Loading commit data...
build Loading commit data...
include Loading commit data...
preparser Loading commit data...
samples Loading commit data...
src Loading commit data...
test Loading commit data...
tools Loading commit data...
.gitignore Loading commit data...
AUTHORS Loading commit data...
ChangeLog Loading commit data...
DEPS Loading commit data...
LICENSE Loading commit data...
LICENSE.strongtalk Loading commit data...
LICENSE.v8 Loading commit data...
LICENSE.valgrind Loading commit data...
Makefile Loading commit data...
Makefile.android Loading commit data...
Makefile.nacl Loading commit data...
OWNERS Loading commit data...
PRESUBMIT.py Loading commit data...