testsuite/systemtap.onthefly/hrtimer_onthefly.exp

   1 source $srcdir/$subdir/onthefly_common.tcl
   2
   3 set test "hrtimer_onthefly"
   4 if {![installtest_p] || ![hrtimer_p]} {
   5    untested "$test"
   6    return
   7 }
   8
   9 # Goal: Ensure that hrtimer probes properly support on-the-fly arming/disarming.
  10 # The script consists of two timer probes where one toggles the condition of the
  11 # other. We then analyze the actual debug statements printed out to ensure the
  12 # toggled probe is armed and disarmed as expected.
  13
  14 # Runs stap on a script with the given arguments
  15 proc run_stap {subtest args script} {
  16
  17    # We always need the DEBUG and -g flags, and -u to avoid probe elision
  18    set args "$args -D DEBUG_STP_ON_THE_FLY -g -u"
  19
  20    # If this is a stress-test, also start a background echo
  21    set echo_pid 0
  22    if {[string match *stress* $subtest]} {
  23       set echo_loop "while \[ true \]; do /bin/echo 1>/dev/null; done"
  24       set echo_pid [exec sh -c $echo_loop &]
  25    }
  26
  27    # Run stap and catch any errors (we will rethrow it later)
  28    set err [catch {eval exec stap -e {$script} $args} out]
  29
  30    # Kill echo
  31    if {$echo_pid} {
  32       kill -INT $echo_pid 1
  33    }
  34
  35    if {$err} {error $out}
  36    return $out
  37 }
  38
  39 # Returns a script with some variables replaced.
  40 #     SUBTEST    name of subtest
  41 #     ENABLED    set to 1 to start the target probe as enabled, 0 as disabled
  42 #     MAXTOGGLES number of times we toggle the target probe condition
  43 #     TIMER      if a number, then it's the period of the target probe and also
  44 #                a fifth of the period which toggles the target probes, if set
  45 #                to 'profile' then instead a timer.profile probe is used to
  46 #                toggle the target probe, if set to 'hardcore' then both a
  47 #                timer.profile probe and a kernel.trace("*") probe is used for
  48 #                toggling, if set to 'max' then a lot of various probe points
  49 #                are used for toggling
  50 proc make_script {SUBTEST ENABLED MAXTOGGLES TIMER} {
  51    global test
  52
  53    set script {
  54
  55       global enabled = ENABLED
  56       global toggles = 0
  57
  58       # Simplification to ensure 'hit' is only printed once. This makes it
  59       # easier later on to verify the output.
  60       global hit = 0
  61
  62       probe timer.us(TIMER) if (enabled) {
  63          if (hit)
  64             next
  65          hit = 1
  66          println("hit")
  67       }
  68
  69       probe timer.us(TIMER5) {
  70          toggles++
  71          hit = 0
  72          if (toggles > MAXTOGGLES)
  73             exit()
  74          else {
  75             println("toggling")
  76             # ensure we also use non-boolean (1 or 0) values
  77             enabled = enabled ? 0 : (randint(2) == 0 ? -1-randint(10000) : 1+randint(10000))
  78          }
  79       }
  80
  81       probe timer.s(360) {
  82          println("timed out")
  83          exit()
  84       }
  85    }
  86
  87    # On ppc64, you can't probe the hcall_* tracepoints (PR17126:
  88    # tracepoints.exp testcase causing stalls/hang on ppc64). This was
  89    # worked around by making a tracepoint blacklist. However, this
  90    # test is using the '-g' (guru) argument to systemtap, which causes
  91    # systemtap to ignore the tracepoint blacklist. So, on ppc64, we'll
  92    # probe all the kernel tracepoints *except* for the ones starting
  93    # with 'h'.
  94    if {[string match ppc* $::tcl_platform(machine)]} {
  95       set kernel_trace {kernel.trace("[a-gi-z]*")}
  96    } else {
  97       set kernel_trace {kernel.trace("*")}
  98    }
  99
 100    # Set in values
 101    set script [string map "TEST $test \
 102                            SUBTEST $SUBTEST \
 103                            ENABLED $ENABLED \
 104                            MAXTOGGLES $MAXTOGGLES" $script]
 105    if {[string match $TIMER "profile"]} {
 106       set script [string map "timer.us(TIMER5) timer.profile \
 107                               TIMER 1500" $script]
 108    } elseif {[string match $TIMER "hardcore"]} {
 109       set script [string map "timer.us(TIMER5) \
 110          {timer.profile, $kernel_trace} \
 111          TIMER 1500" $script]
 112    } elseif {[string match $TIMER "max"]} {
 113       set max_pps "begin, end, error, kernel.function(\"*@workqueue.c\"), \
 114                    process.begin, process.end, $kernel_trace"
 115       if {[uprobes_p]} {
 116          set max_pps "$max_pps, process(\"echo\").function(\"*\")"
 117       }
 118       set max_pps "$max_pps, \
 119           netfilter.pf(\"NFPROTO_IPV4\").hook(\"NF_INET_LOCAL_IN\")?, \
 120           netfilter.pf(\"NFPROTO_IPV4\").hook(\"NF_INET_LOCAL_OUT\")?, \
 121           perf.sw.cpu_clock.sample(1000000)?, timer.profile.tick?"
 122       set script [string map "timer.us(TIMER5) {$max_pps} \
 123                               TIMER 1500" $script]
 124    } else {
 125       set script [string map "TIMER5 [expr $TIMER * 5] \
 126                               TIMER $TIMER" $script]
 127    }
 128
 129    return $script
 130 }
 131
 132 # Creates the pattern which will be used by the is_valid_output proc to
 133 # determine if the output is valid. In other words, given the initial value of
 134 # enabled, the maximum number of toggles, and whether on-the-fly is turned on or
 135 # not, this proc determines what will be the output of stap.
 136 proc make_pattern {subtest start_enabled maxtoggles} {
 137    set pattern ""
 138
 139    if {![is_dyninst_subtest $subtest] && !$start_enabled} {
 140       lappend pattern "* not starting (hrtimer) pidx ?"
 141    }
 142
 143    # For each toggle:
 144    #  - if we were enabled, then we would had a 'hit' line
 145    #  - if i == maxtoggles, then we'll exit so nothing more will be printed
 146    #  - if i < maxtoggles, then the timer probe will output 'toggling' followed
 147    #    by a 'disabling' or 'enabling' line if on-the-fly is turned on
 148    for {set i 0} {$i <= $maxtoggles} {incr i} {
 149       if {$start_enabled} {
 150          lappend pattern "hit"
 151       }
 152       if {$i < $maxtoggles} {
 153          lappend pattern "toggling"
 154          if {$start_enabled} {
 155             set start_enabled 0
 156             if {![is_dyninst_subtest $subtest]} {
 157                lappend pattern "* disabling (hrtimer) pidx ?"
 158             }
 159          } else {
 160             set start_enabled 1
 161             if {![is_dyninst_subtest $subtest] && $i < $maxtoggles} {
 162                lappend pattern "* enabling (hrtimer) pidx ?"
 163             }
 164          }
 165       }
 166    }
 167
 168    return $pattern
 169 }
 170
 171 # NB: dyninst-targeted subtests must have name starting with 'dyninst_'
 172
 173 # Check that dyninst timer probes still work well (starting enabled)
 174 run_subtest_valid "dyninst_start_enabled" 100 5 100000 \
 175    --runtime=dyninst
 176
 177 # Check that dyninst timer probes still work well (starting disabled)
 178 run_subtest_valid "dyninst_start_disabled" 0 5 100000 \
 179    --runtime=dyninst
 180
 181 # Various on-the-fly tests
 182
 183 # Toggle 0, 1, 2, 3, 4, and 5 times. This is important since we test if the
 184 # probes finish well when disabled/enabled. NB: We try on various values for
 185 # ENABLED just to ensure not just 0/1 works as a condition
 186
 187 run_subtest_valid "otf_finish_at_start_disabled" 0         0 100000
 188 run_subtest_valid "otf_finish_at_start_enabled"  100       0 100000
 189 run_subtest_valid "otf_start_disabled_iter_1"    0         1 100000
 190 run_subtest_valid "otf_start_enabled_iter_1"     0x7f      1 100000
 191 run_subtest_valid "otf_start_disabled_iter_2"    0         2 100000
 192 run_subtest_valid "otf_start_enabled_iter_2"     -1000     2 100000
 193 run_subtest_valid "otf_start_disabled_iter_3"    0         3 100000
 194 run_subtest_valid "otf_start_enabled_iter_3"     658       3 100000
 195 run_subtest_valid "otf_start_disabled_iter_4"    0         4 100000
 196 run_subtest_valid "otf_start_enabled_iter_4"     -1        4 100000
 197 run_subtest_valid "otf_start_disabled_iter_5"    0         5 100000
 198 run_subtest_valid "otf_start_enabled_iter_5"     123456789 5 100000
 199
 200 # Small interval tests
 201
 202 run_subtest_valid "otf_timer_10ms"    1 5 10000
 203 run_subtest_valid "otf_timer_5ms"    -1 5 5000
 204
 205 # NB: if we go any shorter, the kernel might not have a chance to run
 206 # systemtap_module_refresh() before the next toggling occurs, throwing off the
 207 # expected output.
 208
 209 # Stress tests
 210
 211 # These tests are not validated, i.e. their outputs are not checked against a
 212 # pattern (see NB above why). Instead, they're just meant to stress the
 213 # on-the-fly mechanism to ensure stap/the kernel doesn't die. So if stap is
 214 # successfully run and terminated, we just default to a pass.
 215
 216 run_subtest_stress "otf_stress_2ms_iter_50"   1 50 2000
 217 run_subtest_stress "otf_stress_1ms_iter_50"   1 50 1000
 218 run_subtest_stress "otf_stress_500us_iter_50" 1 50 500
 219 run_subtest_stress "otf_stress_100us_iter_50" 1 50 100
 220
 221 run_subtest_stress "otf_stress_prof_iter_2000" 1 2000 profile
 222
 223 # Use 100 us for interval
 224 run_subtest_stress "otf_stress_hard_iter_2000" 1 2000 hardcore \
 225    -D STP_ON_THE_FLY_INTERVAL=100000
 226
 227 run_subtest_stress "otf_stress_max_iter_5000" 1 5000 max \
 228    -D STP_ON_THE_FLY_INTERVAL=100000